audio_service icon indicating copy to clipboard operation
audio_service copied to clipboard

firebase + audio_service: application launched when it should not

Open yanivshaked opened this issue 3 years ago • 56 comments

Documented behaviour

Expected behavior: During incoming push notification (firebase messaging), the application should NOT be launched.

Actual behaviour

The application is fully launched in the background when a push notification is received.

Minimal reproduction project

https://github.com/12Tech12/audio_service In other to make the example operational, you should:

  1. Put in your google-services.json file under android/app directory
  2. Search and replace all phrases com.twtech.twelveqa to the package name supported by your google-services.json (com.ryanheise.audioserviceexample or other)

Reproduction steps

  1. Copy the firebase messaging token from the log printed, for example:
Cloud Messaging Token is c9NQO3mTRwqvbVKVqwlZi2:APA91bEMZHEN8kt083sfukOxTIFy-gq8RUen7TQy3Wgvw-7hwRCQyAGmaqdedFc6bThfBIij911p4V3snahxRjl13um4yF67Ywu7HtiycdxcjXweDgN0ANBjB1sVnhtKSjfvcat6WIEB
  1. Close the application (also from background).
  2. Use firebase console to send a push notification to the device (use the token copied on step 1).
  3. The log "Application fully loaded!" will be displayed, indicating the application was fully loaded on the background due to the push notification (and it should NOT).

Output of flutter doctor

Doctor summary (to see all details, run flutter doctor -v):
[√] Flutter (Channel stable, 2.5.3, on Microsoft Windows [Version 10.0.19042.1348], locale he-IL)
[√] Android toolchain - develop for Android devices (Android SDK version 31.0.0-rc3)
[√] Chrome - develop for the web
[√] Android Studio (version 2020.3)
[√] VS Code (version 1.62.2)
[√] Connected device (3 available)

• No issues found!```
### Devices exhibiting the bug
Device: Android OnePlus 8T
OS Version: 11

yanivshaked avatar Nov 16 '21 14:11 yanivshaked

Thank you for the report, I shall look into this tomorrow.

ryanheise avatar Nov 16 '21 16:11 ryanheise

It may take me a while before I can set up an environment to test this, but in the meantime would you be willing to provide a stack trace inside of AudioServicePlugin.getFlutterEngine()?

The easiest way without tools would be to just insert this line inside of that method:

    public static synchronized FlutterEngine getFlutterEngine(Context context) {
        new Exception().printStackTrace(); // INSERT THIS LINE

This engine should only be used by the activity and by this plugin's own service (AudioService). firebase_messaging has these intent filters:

    <service
      android:name=".FlutterFirebaseMessagingBackgroundService"
      android:permission="android.permission.BIND_JOB_SERVICE"
      android:exported="false"/>
    <service android:name=".FlutterFirebaseMessagingService"
      android:exported="false">
      <intent-filter>
        <action android:name="com.google.firebase.MESSAGING_EVENT"/>
      </intent-filter>
    </service>
    <receiver
      android:name=".FlutterFirebaseMessagingReceiver"
      android:exported="true"
      android:permission="com.google.android.c2dm.permission.SEND">
      <intent-filter>
        <action android:name="com.google.android.c2dm.intent.RECEIVE" />
      </intent-filter>
    </receiver>

But looking at those, it seems firebase_messaging instantiates its own FlutterEngine so this should not happen.

The only thing I can think of is if the activity receives the intent, but according to your repro project's manifest that only happens if you click on the notification which is not the case here.

So a stack trace will help narrow down who is actually instantiating audio_service's own FlutterEngine.

ryanheise avatar Nov 17 '21 04:11 ryanheise

Sure, anything I can do to help find a solution to this issue ASAP. On it, will post shortly.

yanivshaked avatar Nov 17 '21 05:11 yanivshaked

In addition, I have provided you with maintenance permission to the fork, so in case you would like to add more logs / try out different solution, you can simply push the changes to the fork, I can quickly test them and report.

yanivshaked avatar Nov 17 '21 06:11 yanivshaked

Deleted my previous message, as it was incorrect. When starting the application regularly (flutter run or app icon click), I am getting the following log:


2021-11-17 08:08:33.813 31557-31557/com.twtech.twelveqa D/ApplicationLoaders: Returning zygote-cached class loader: /system/framework/android.test.base.jar
2021-11-17 08:08:33.769 31557-31557/? I/libc: SetHeapTaggingLevel: tag level set to 0
2021-11-17 08:08:33.771 31557-31557/? I/twtech.twelveq: Late-enabling -Xcheck:jni
2021-11-17 08:08:33.784 31557-31557/? I/twtech.twelveq: Unquickening 21 vdex files!
2021-11-17 08:08:29.047 2435-2435/? D/OpSWarpChargingView: level is same as latest one [95]
2021-11-17 08:08:33.769 31557-31557/? I/libc: SetHeapTaggingLevel: tag level set to 0
2021-11-17 08:08:33.784 31557-31557/? E/twtech.twelveq: Unknown bits set in runtime_flags: 0x800000
2021-11-17 08:08:33.771 31557-31557/? I/twtech.twelveq: Late-enabling -Xcheck:jni
2021-11-17 08:08:33.784 31557-31557/? I/twtech.twelveq: Unquickening 21 vdex files!
2021-11-17 08:08:33.784 31557-31557/? E/twtech.twelveq: Unknown bits set in runtime_flags: 0x800000
2021-11-17 08:08:33.769 31557-31557/? I/libc: SetHeapTaggingLevel: tag level set to 0
2021-11-17 08:08:33.771 31557-31557/? I/twtech.twelveq: Late-enabling -Xcheck:jni
2021-11-17 08:08:33.784 31557-31557/? I/twtech.twelveq: Unquickening 21 vdex files!
2021-11-17 08:08:33.784 31557-31557/? E/twtech.twelveq: Unknown bits set in runtime_flags: 0x800000
2021-11-17 08:08:33.824 31557-31557/com.twtech.twelveqa I/Perf: Connecting to perf service.
2021-11-17 08:08:33.828 31557-31557/com.twtech.twelveqa D/NetworkSecurityConfig: No Network Security Config specified, using platform default
2021-11-17 08:08:33.828 31557-31557/com.twtech.twelveqa D/NetworkSecurityConfig: No Network Security Config specified, using platform default
2021-11-17 08:08:33.834 31557-31557/com.twtech.twelveqa I/FirebaseApp: Device unlocked: initializing all Firebase APIs for app [DEFAULT]
2021-11-17 08:08:33.839 31557-31557/com.twtech.twelveqa I/FirebaseInitProvider: FirebaseApp initialization successful
2021-11-17 08:08:33.839 31557-31557/com.twtech.twelveqa D/FLTFireContextHolder: received application context.
2021-11-17 08:08:33.842 31557-27594/com.twtech.twelveqa E/sqlite3_android: ONEPLUS_NAME_PARTS_MATCH SQLITE_OK
2021-11-17 08:08:33.853 31557-31557/com.twtech.twelveqa E/libprocessgroup: set_timerslack_ns write failed: Operation not permitted
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err: java.lang.Exception
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at com.ryanheise.audioservice.AudioServicePlugin.getFlutterEngine(AudioServicePlugin.java:68)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at com.ryanheise.audioservice.AudioServiceActivity.provideFlutterEngine(AudioServiceActivity.java:12)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at io.flutter.embedding.android.FlutterActivityAndFragmentDelegate.setupFlutterEngine(FlutterActivityAndFragmentDelegate.java:235)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at io.flutter.embedding.android.FlutterActivityAndFragmentDelegate.onAttach(FlutterActivityAndFragmentDelegate.java:162)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at io.flutter.embedding.android.FlutterActivity.onCreate(FlutterActivity.java:430)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.Activity.performCreate(Activity.java:8006)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.Activity.performCreate(Activity.java:7990)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1329)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:3595)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:3786)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.servertransaction.LaunchActivityItem.execute(LaunchActivityItem.java:85)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.servertransaction.TransactionExecutor.executeCallbacks(TransactionExecutor.java:135)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.servertransaction.TransactionExecutor.execute(TransactionExecutor.java:95)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2257)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.os.Handler.dispatchMessage(Handler.java:106)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.os.Looper.loop(Looper.java:233)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.main(ActivityThread.java:8030)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at java.lang.reflect.Method.invoke(Native Method)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:631)
2021-11-17 08:08:33.863 31557-31557/com.twtech.twelveqa W/System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:978)
2021-11-17 08:08:33.869 31557-27608/com.twtech.twelveqa I/ResourceExtractor: Found extracted resources res_timestamp-1-1637128743812
2021-11-17 08:08:33.869 31557-31557/com.twtech.twelveqa W/twtech.twelveqa: type=1400 audit(0.0:19131): avc: denied { read } for name="max_map_count" dev="proc" ino=24053391 scontext=u:r:untrusted_app_29:s0:c160,c259,c512,c768 tcontext=u:object_r:proc_max_map_count:s0 tclass=file permissive=0 app=com.twtech.twelveqa
2021-11-17 08:08:33.878 31557-31557/com.twtech.twelveqa I/AdrenoGLES-0: QUALCOMM build                   : 3571974a10, I64bd74b5bd
    Build Date                       : 09/11/20
    OpenGL ES Shader Compiler Version: EV031.32.02.00
    Local Branch                     : 
    Remote Branch                    : refs/tags/AU_LINUX_ANDROID_LA.UM.9.12.10.00.00.582.274
    Remote Branch                    : NONE
    Reconstruct Branch               : NOTHING
2021-11-17 08:08:33.878 31557-31557/com.twtech.twelveqa I/AdrenoGLES-0: Build Config                     : S P 10.0.5 AArch64
2021-11-17 08:08:33.878 31557-31557/com.twtech.twelveqa I/AdrenoGLES-0: Driver Path                      : /vendor/lib64/egl/libGLESv2_adreno.so
2021-11-17 08:08:33.880 31557-31557/com.twtech.twelveqa I/AdrenoGLES-0: PFP: 0x016dd091, ME: 0x00000000
2021-11-17 08:08:33.894 31557-31557/com.twtech.twelveqa D/MediaBrowserCompat: Connecting to a MediaBrowserService.
2021-11-17 08:08:33.910 31557-31557/com.twtech.twelveqa I/TextToSpeech: Sucessfully bound to com.google.android.tts
2021-11-17 08:08:33.914 31557-31557/com.twtech.twelveqa D/PathProviderPlugin: Don't use TaskQueues.
2021-11-17 08:08:33.915 31557-31557/com.twtech.twelveqa W/System.err: java.lang.Exception
2021-11-17 08:08:33.915 31557-31557/com.twtech.twelveqa W/System.err:     at com.ryanheise.audioservice.AudioServicePlugin.getFlutterEngine(AudioServicePlugin.java:68)
2021-11-17 08:08:33.915 31557-31557/com.twtech.twelveqa W/System.err:     at com.ryanheise.audioservice.AudioServicePlugin.onAttachedToActivity(AudioServicePlugin.java:261)
2021-11-17 08:08:33.915 31557-31557/com.twtech.twelveqa W/System.err:     at io.flutter.embedding.engine.FlutterEngineConnectionRegistry.attachToActivityInternal(FlutterEngineConnectionRegistry.java:362)
2021-11-17 08:08:33.915 31557-31557/com.twtech.twelveqa W/System.err:     at io.flutter.embedding.engine.FlutterEngineConnectionRegistry.attachToActivity(FlutterEngineConnectionRegistry.java:344)
2021-11-17 08:08:33.915 31557-31557/com.twtech.twelveqa W/System.err:     at io.flutter.embedding.android.FlutterActivityAndFragmentDelegate.onAttach(FlutterActivityAndFragmentDelegate.java:176)
2021-11-17 08:08:33.915 31557-31557/com.twtech.twelveqa W/System.err:     at io.flutter.embedding.android.FlutterActivity.onCreate(FlutterActivity.java:430)
2021-11-17 08:08:33.915 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.Activity.performCreate(Activity.java:8006)
2021-11-17 08:08:33.915 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.Activity.performCreate(Activity.java:7990)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.Instrumentation.callActivityOnCreate(Instrumentation.java:1329)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:3595)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:3786)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.servertransaction.LaunchActivityItem.execute(LaunchActivityItem.java:85)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.servertransaction.TransactionExecutor.executeCallbacks(TransactionExecutor.java:135)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.servertransaction.TransactionExecutor.execute(TransactionExecutor.java:95)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2257)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at android.os.Handler.dispatchMessage(Handler.java:106)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at android.os.Looper.loop(Looper.java:233)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.main(ActivityThread.java:8030)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at java.lang.reflect.Method.invoke(Native Method)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:631)
2021-11-17 08:08:33.916 31557-31557/com.twtech.twelveqa W/System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:978)
2021-11-17 08:08:33.925 31557-31557/com.twtech.twelveqa W/twtech.twelveq: Accessing hidden method Landroid/view/accessibility/AccessibilityNodeInfo;->getSourceNodeId()J (greylist,test-api, reflection, allowed)
2021-11-17 08:08:33.925 31557-31557/com.twtech.twelveqa W/twtech.twelveq: Accessing hidden method Landroid/view/accessibility/AccessibilityRecord;->getSourceNodeId()J (greylist, reflection, allowed)
2021-11-17 08:08:33.925 31557-31557/com.twtech.twelveqa W/twtech.twelveq: Accessing hidden field Landroid/view/accessibility/AccessibilityNodeInfo;->mChildNodeIds:Landroid/util/LongArray; (greylist, reflection, allowed)
2021-11-17 08:08:33.925 31557-31557/com.twtech.twelveqa W/twtech.twelveq: Accessing hidden method Landroid/util/LongArray;->get(I)J (greylist, reflection, allowed)
2021-11-17 08:08:33.949 31557-31557/com.twtech.twelveqa V/ViewRootImpl: The specified message queue synchronization  barrier token has not been posted or has already been removed
2021-11-17 08:08:33.956 31557-31557/com.twtech.twelveqa D/OpScreenModeManager: setRefreshRate view io.flutter.embedding.android.FlutterSurfaceView{72be442 V.E...... ......I. 0,0-0,0} viewRate 0 width 0 height 0
2021-11-17 08:08:33.956 31557-31557/com.twtech.twelveqa D/OpScreenModeManager: create mRatio 1.2
2021-11-17 08:08:33.990 31557-27632/com.twtech.twelveqa I/flutter: Observatory listening on http://127.0.0.1:42807/EixeMaNGyjI=/
2021-11-17 08:08:34.072 31557-31557/com.twtech.twelveqa D/OpScreenModeManager: setRefreshRate parent io.flutter.embedding.android.FlutterView{a487c53 VFE...... ......ID 0,0-1080,2355 #1} parent width 1080 parent height 2355 mRatio 1.2
2021-11-17 08:08:34.072 31557-31557/com.twtech.twelveqa D/OpScreenModeManager: setRefreshRate view io.flutter.embedding.android.FlutterSurfaceView{72be442 V.E...... ......ID 0,0-1080,2355} viewRate 1 width 1080 height 2355
2021-11-17 08:08:34.072 31557-31557/com.twtech.twelveqa D/OpScreenModeManager: setRefreshRate token android.os.BinderProxy@7e99239 rate 1 mCurrentRate 0 tmpRate:2
2021-11-17 08:08:34.073 31557-31557/com.twtech.twelveqa D/OpScreenModeManager: updateScenario fullScreen 1
2021-11-17 08:08:34.097 31557-31557/com.twtech.twelveqa W/Choreographer: Already have a pending vsync event.  There should only be one at a time.
2021-11-17 08:08:34.099 31557-31557/com.twtech.twelveqa I/TextToSpeech: Connected to ComponentInfo{com.google.android.tts/com.google.android.apps.speech.tts.googletts.service.GoogleTTSService}
2021-11-17 08:08:34.102 31557-27608/com.twtech.twelveqa I/TextToSpeech: Set up connection to ComponentInfo{com.google.android.tts/com.google.android.apps.speech.tts.googletts.service.GoogleTTSService}
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err: java.lang.Exception
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err:     at com.ryanheise.audioservice.AudioServicePlugin.getFlutterEngine(AudioServicePlugin.java:68)
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err:     at com.ryanheise.audioservice.AudioService.onCreate(AudioService.java:282)
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.handleCreateService(ActivityThread.java:4390)
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.access$2000(ActivityThread.java:274)
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2123)
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err:     at android.os.Handler.dispatchMessage(Handler.java:106)
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err:     at android.os.Looper.loop(Looper.java:233)
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.main(ActivityThread.java:8030)
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err:     at java.lang.reflect.Method.invoke(Native Method)
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:631)
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa W/System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:978)
2021-11-17 08:08:34.117 31557-31557/com.twtech.twelveqa I/System.out: flutterEngine warmed up
2021-11-17 08:08:34.119 31557-31557/com.twtech.twelveqa E/TTS: getDefaultLocale: Attempt to invoke virtual method 'java.util.Locale android.speech.tts.Voice.getLocale()' on a null object reference
2021-11-17 08:08:34.369 31557-27643/com.twtech.twelveqa D/Choreographer: initialValue myPid:31557 myTid:27643 choreographer:android.view.Choreographer@2d02b3e
2021-11-17 08:08:34.370 31557-31557/com.twtech.twelveqa W/twtech.twelveq: Accessing hidden method Landroid/media/AudioTrack;->getLatency()I (greylist, reflection, allowed)
2021-11-17 08:08:34.371 31557-31557/com.twtech.twelveqa I/ExoPlayerImpl: Init fc37d9f [ExoPlayerLib/2.15.0] [OnePlus8T, KB2003, OnePlus, 30]
2021-11-17 08:08:34.382 31557-27636/com.twtech.twelveqa I/FirebaseApp: Device unlocked: initializing all Firebase APIs for app Twelve
2021-11-17 08:08:34.388 31557-27648/com.twtech.twelveqa E/sqlite3_android: ONEPLUS_NAME_PARTS_MATCH SQLITE_OK
2021-11-17 08:08:34.390 31557-31557/com.twtech.twelveqa I/TetheringManager: registerTetheringEventCallback:com.twtech.twelveqa
2021-11-17 08:08:34.426 31557-27610/com.twtech.twelveqa I/flutter: Is notifications authorized? => true
2021-11-17 08:08:34.445 31557-27610/com.twtech.twelveqa I/flutter: Cloud Messaging Token is cvYJNS1zS4O_Ca6lCDfNsr:APA91bGdXwChgYtbpsFV99NMvaehdOIPHIFUsFSvLAseTCow8L0DPSfZu7hehLC9z_fMY8ypyD6MG-83PgUYVjGze0bLJC_mlJ6zVWOuenfyrGwC4HTMWU6iAv5wrC7YAuol3JQEJr4n
2021-11-17 08:08:34.447 31557-27610/com.twtech.twelveqa I/flutter: Application fully loaded!
2021-11-17 08:08:34.450 31557-27650/com.twtech.twelveqa I/DpmTcmClient: RegisterTcmMonitor from: $Proxy1
2021-11-17 08:08:34.452 31557-31557/com.twtech.twelveqa W/FlutterJNI: FlutterJNI.setRefreshRateFPS called more than once
2021-11-17 08:08:34.454 31557-27654/com.twtech.twelveqa W/FlutterJNI: FlutterJNI.loadLibrary called more than once
2021-11-17 08:08:34.454 31557-27658/com.twtech.twelveqa W/FlutterJNI: FlutterJNI.prefetchDefaultFontManager called more than once
2021-11-17 08:08:34.455 31557-27608/com.twtech.twelveqa I/ResourceExtractor: Found extracted resources res_timestamp-1-1637128743812
2021-11-17 08:08:34.461 31557-31557/com.twtech.twelveqa W/FlutterJNI: FlutterJNI.init called more than once
2021-11-17 08:08:34.467 31557-31557/com.twtech.twelveqa I/FLTFireBGExecutor: Creating background FlutterEngine instance, with args: [--enable-dart-profiling]
2021-11-17 08:08:34.473 31557-31557/com.twtech.twelveqa I/TextToSpeech: Sucessfully bound to com.google.android.tts
2021-11-17 08:08:34.474 31557-31557/com.twtech.twelveqa D/PathProviderPlugin: Don't use TaskQueues.
2021-11-17 08:08:34.475 31557-31557/com.twtech.twelveqa I/TextToSpeech: Connected to ComponentInfo{com.google.android.tts/com.google.android.apps.speech.tts.googletts.service.GoogleTTSService}
2021-11-17 08:08:34.480 31557-27608/com.twtech.twelveqa I/TextToSpeech: Set up connection to ComponentInfo{com.google.android.tts/com.google.android.apps.speech.tts.googletts.service.GoogleTTSService}
2021-11-17 08:08:34.484 31557-31557/com.twtech.twelveqa E/TTS: getDefaultLocale: Attempt to invoke virtual method 'java.util.Locale android.speech.tts.Voice.getLocale()' on a null object reference
2021-11-17 08:08:34.700 31557-31557/com.twtech.twelveqa I/FLTFireMsgService: FlutterFirebaseMessagingBackgroundService started!
2021-11-17 08:08:35.044 31557-27611/com.twtech.twelveqa D/twtech.twelveq: Successfully load libgui-plugin.so, this=0x7e57dbc298
2021-11-17 08:08:35.050 31557-31557/com.twtech.twelveqa D/OpScreenModeManager: setRefreshRate parent io.flutter.embedding.android.FlutterView{a487c53 VFE...... ........ 0,0-1080,2355 #1} parent width 1080 parent height 2355 mRatio 1.2
2021-11-17 08:08:35.050 31557-31557/com.twtech.twelveqa D/OpScreenModeManager: setRefreshRate view io.flutter.embedding.android.FlutterSurfaceView{72be442 V.E...... ........ 0,0-1080,2355} viewRate 1 width 1080 height 2355
2021-11-17 08:08:35.063 31557-31557/com.twtech.twelveqa D/DecorView: onWindowFocusChangedFromViewRoot hasFocus: true, DecorView@f2bc428[AudioServiceActivity]
2021-11-17 08:08:35.064 31557-31557/com.twtech.twelveqa D/ViewRootImpl[AudioServiceActivity]: windowFocusChanged hasFocus=true inTouchMode=true
2021-11-17 08:08:35.080 31557-27603/com.twtech.twelveqa W/DisplayEventDispatcher: dispatcher 0x7c03cea690 ~ ignoring unknown event type 0x6d746f6e
2021-11-17 08:08:35.080 31557-27643/com.twtech.twelveqa W/DisplayEventDispatcher: dispatcher 0x7bb3cd4fd0 ~ ignoring unknown event type 0x6d746f6e
2021-11-17 08:08:35.081 31557-31557/com.twtech.twelveqa W/DisplayEventDispatcher: dispatcher 0x7bb3ccb550 ~ ignoring unknown event type 0x6d746f6e
2021-11-17 08:08:35.564 31557-27644/com.twtech.twelveqa W/VideoCapabilities: Unsupported mime image/vnd.android.heic
2021-11-17 08:08:35.567 31557-27644/com.twtech.twelveqa W/VideoCapabilities: Unrecognized profile/level 0/3 for video/mpeg2
2021-11-17 08:08:35.567 31557-27644/com.twtech.twelveqa W/VideoCapabilities: Unrecognized profile/level 0/3 for video/mpeg2
2021-11-17 08:08:35.596 31557-27672/com.twtech.twelveqa D/CCodec: allocate(c2.android.mp3.decoder)
2021-11-17 08:08:35.597 31557-27672/com.twtech.twelveqa I/Codec2Client: Available Codec2 services: "software"
2021-11-17 08:08:35.599 31557-27672/com.twtech.twelveqa I/CCodec: Created component [c2.android.mp3.decoder]
2021-11-17 08:08:35.600 31557-27672/com.twtech.twelveqa D/CCodecConfig: read media type: audio/mpeg
2021-11-17 08:08:35.601 31557-27672/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.max-count.values
2021-11-17 08:08:35.601 31557-27672/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: output.subscribed-indices.values
2021-11-17 08:08:35.601 31557-27672/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: input.buffers.allocator-ids.values
2021-11-17 08:08:35.601 31557-27672/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.allocator-ids.values
2021-11-17 08:08:35.601 31557-27672/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.allocator-ids.values
2021-11-17 08:08:35.601 31557-27672/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.pool-ids.values
2021-11-17 08:08:35.601 31557-27672/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.pool-ids.values
2021-11-17 08:08:35.602 31557-27672/com.twtech.twelveqa I/CCodecConfig: query failed after returning 7 values (BAD_INDEX)
2021-11-17 08:08:35.602 31557-27672/com.twtech.twelveqa D/CCodecConfig: c2 config diff is Dict {
      c2::u32 coded.bitrate.value = 64000
      c2::u32 input.buffers.max-size.value = 8192
      c2::u32 input.delay.value = 0
      string input.media-type.value = "audio/mpeg"
      string output.media-type.value = "audio/raw"
      c2::u32 raw.channel-count.value = 2
      c2::u32 raw.sample-rate.value = 44100
    }
2021-11-17 08:08:35.602 31557-27672/com.twtech.twelveqa D/CCodec: [c2.android.mp3.decoder] buffers are bound to CCodec for this session
2021-11-17 08:08:35.602 31557-27672/com.twtech.twelveqa D/CCodecConfig: no c2 equivalents for flags
2021-11-17 08:08:35.602 31557-27672/com.twtech.twelveqa D/CCodecConfig: config failed => CORRUPTED
2021-11-17 08:08:35.602 31557-27672/com.twtech.twelveqa W/Codec2Client: query -- param skipped: index = 1107298332.
2021-11-17 08:08:35.602 31557-27672/com.twtech.twelveqa D/CCodec: client requested max input size 4096, which is smaller than what component recommended (8192); overriding with component recommendation.
2021-11-17 08:08:35.602 31557-27672/com.twtech.twelveqa W/CCodec: This behavior is subject to change. It is recommended that app developers double check whether the requested max input size is in reasonable range.
2021-11-17 08:08:35.602 31557-27672/com.twtech.twelveqa D/CCodec: setup formats input: AMessage(what = 0x00000000) = {
      int32_t channel-count = 2
      int32_t max-input-size = 8192
      string mime = "audio/mpeg"
      int32_t sample-rate = 44100
    } and output: AMessage(what = 0x00000000) = {
      int32_t channel-count = 2
      string mime = "audio/raw"
      int32_t sample-rate = 44100
    }
2021-11-17 08:08:35.603 31557-27672/com.twtech.twelveqa W/Codec2Client: query -- param skipped: index = 1342179345.
2021-11-17 08:08:35.603 31557-27672/com.twtech.twelveqa W/Codec2Client: query -- param skipped: index = 2415921170.
2021-11-17 08:08:35.603 31557-27672/com.twtech.twelveqa E/FMQ: grantorIdx must be less than 3
2021-11-17 08:08:35.603 31557-27672/com.twtech.twelveqa E/FMQ: grantorIdx must be less than 3
2021-11-17 08:08:35.603 31557-27672/com.twtech.twelveqa D/CCodecBufferChannel: [c2.android.mp3.decoder#94] Created input block pool with allocatorID 16 => poolID 17 - OK (0)
2021-11-17 08:08:35.604 31557-27672/com.twtech.twelveqa I/CCodecBufferChannel: [c2.android.mp3.decoder#94] Created output block pool with allocatorID 16 => poolID 1099 - OK
2021-11-17 08:08:35.604 31557-27672/com.twtech.twelveqa D/CCodecBufferChannel: [c2.android.mp3.decoder#94] Configured output block pool ids 1099 => OK
2021-11-17 08:08:35.604 31557-27672/com.twtech.twelveqa E/ion: ioctl c0044901 failed with code -1: Inappropriate ioctl for device
2021-11-17 08:08:35.608 31557-27672/com.twtech.twelveqa E/FMQ: grantorIdx must be less than 3
2021-11-17 08:08:35.610 31557-27676/com.twtech.twelveqa E/FMQ: grantorIdx must be less than 3
2021-11-17 08:08:35.611 31557-27644/com.twtech.twelveqa D/AudioTrack: set(): streamType -1, sampleRate 44100, format 0x1, channelMask 0x3, frameCount 14144, flags #0, notificationFrames 0, sessionId 4337, transferType 3, uid -1, pid -1
2021-11-17 08:08:35.616 31557-27644/com.twtech.twelveqa D/AudioTrack: Uid 10928 AudioTrack::setVolume left 1.000000 right 1.000000
2021-11-17 08:08:40.610 31557-27675/com.twtech.twelveqa D/BufferPoolAccessor2.0: bufferpool2 0x7c43d420c8 : 5(40960 size) total buffers - 4(32768 size) used buffers - 0/5 (recycle/alloc) - 4/36 (fetch/transfer)
2021-11-17 08:08:40.610 31557-27675/com.twtech.twelveqa D/BufferPoolAccessor2.0: evictor expired: 1, evicted: 1


Note that the callstack is printed 3 times.

When application is started in the background due to the push notification (After fully terminating the app), I am getting the following log:


2021-11-17 08:11:11.556 27921-27921/? I/libc: SetHeapTaggingLevel: tag level set to 0
2021-11-17 08:11:11.558 27921-27921/? I/twtech.twelveq: Late-enabling -Xcheck:jni
2021-11-17 08:11:10.846 2435-2435/? E/NavigationButtonUtils: res.getInteger(resId) = 2
2021-11-17 08:11:11.569 27921-27921/? I/twtech.twelveq: Unquickening 21 vdex files!
2021-11-17 08:11:11.569 27921-27921/? E/twtech.twelveq: Unknown bits set in runtime_flags: 0x800000
2021-11-17 08:11:11.556 27921-27921/? I/libc: SetHeapTaggingLevel: tag level set to 0
2021-11-17 08:11:11.558 27921-27921/? I/twtech.twelveq: Late-enabling -Xcheck:jni
2021-11-17 08:11:11.569 27921-27921/? I/twtech.twelveq: Unquickening 21 vdex files!
2021-11-17 08:11:11.569 27921-27921/? E/twtech.twelveq: Unknown bits set in runtime_flags: 0x800000
2021-11-17 08:11:11.556 27921-27921/? I/libc: SetHeapTaggingLevel: tag level set to 0
2021-11-17 08:11:11.558 27921-27921/? I/twtech.twelveq: Late-enabling -Xcheck:jni
2021-11-17 08:11:11.569 27921-27921/? I/twtech.twelveq: Unquickening 21 vdex files!
2021-11-17 08:11:11.569 27921-27921/? E/twtech.twelveq: Unknown bits set in runtime_flags: 0x800000
2021-11-17 08:11:11.646 27921-27921/com.twtech.twelveqa D/ApplicationLoaders: Returning zygote-cached class loader: /system/framework/android.test.base.jar
2021-11-17 08:11:11.684 27921-27921/com.twtech.twelveqa I/Perf: Connecting to perf service.
2021-11-17 08:11:11.694 27921-27921/com.twtech.twelveqa D/NetworkSecurityConfig: No Network Security Config specified, using platform default
2021-11-17 08:11:11.695 27921-27921/com.twtech.twelveqa D/NetworkSecurityConfig: No Network Security Config specified, using platform default
2021-11-17 08:11:11.714 27921-27921/com.twtech.twelveqa I/FirebaseApp: Device unlocked: initializing all Firebase APIs for app [DEFAULT]
2021-11-17 08:11:11.731 27921-27921/com.twtech.twelveqa I/FirebaseInitProvider: FirebaseApp initialization successful
2021-11-17 08:11:11.732 27921-27921/com.twtech.twelveqa D/FLTFireContextHolder: received application context.
2021-11-17 08:11:11.734 27921-27945/com.twtech.twelveqa E/sqlite3_android: ONEPLUS_NAME_PARTS_MATCH SQLITE_OK
2021-11-17 08:11:11.747 27921-27921/com.twtech.twelveqa D/FLTFireMsgReceiver: broadcast received for message
2021-11-17 08:11:11.771 27921-27967/com.twtech.twelveqa I/FLTFireMsgService: Service has not yet started, messages will be queued.
2021-11-17 08:11:11.775 27921-27968/com.twtech.twelveqa I/ResourceExtractor: Found extracted resources res_timestamp-1-1637128743812
2021-11-17 08:11:11.792 27921-27921/com.twtech.twelveqa I/FLTFireBGExecutor: Creating background FlutterEngine instance.
2021-11-17 08:11:11.802 27921-27921/com.twtech.twelveqa W/FlutterJNI: FlutterJNI.setRefreshRateFPS called more than once
2021-11-17 08:11:11.804 27921-27985/com.twtech.twelveqa W/FlutterJNI: FlutterJNI.loadLibrary called more than once
2021-11-17 08:11:11.804 27921-27968/com.twtech.twelveqa I/ResourceExtractor: Found extracted resources res_timestamp-1-1637128743812
2021-11-17 08:11:11.806 27921-27921/com.twtech.twelveqa W/FlutterJNI: FlutterJNI.init called more than once
2021-11-17 08:11:11.809 27921-27921/com.twtech.twelveqa W/twtech.twelveqa: type=1400 audit(0.0:19140): avc: denied { read } for name="max_map_count" dev="proc" ino=24054458 scontext=u:r:untrusted_app_29:s0:c160,c259,c512,c768 tcontext=u:object_r:proc_max_map_count:s0 tclass=file permissive=0 app=com.twtech.twelveqa
2021-11-17 08:11:11.832 27921-27921/com.twtech.twelveqa I/AdrenoGLES-0: QUALCOMM build                   : 3571974a10, I64bd74b5bd
    Build Date                       : 09/11/20
    OpenGL ES Shader Compiler Version: EV031.32.02.00
    Local Branch                     : 
    Remote Branch                    : refs/tags/AU_LINUX_ANDROID_LA.UM.9.12.10.00.00.582.274
    Remote Branch                    : NONE
    Reconstruct Branch               : NOTHING
2021-11-17 08:11:11.832 27921-27921/com.twtech.twelveqa I/AdrenoGLES-0: Build Config                     : S P 10.0.5 AArch64
2021-11-17 08:11:11.832 27921-27921/com.twtech.twelveqa I/AdrenoGLES-0: Driver Path                      : /vendor/lib64/egl/libGLESv2_adreno.so
2021-11-17 08:11:11.845 27921-27921/com.twtech.twelveqa I/AdrenoGLES-0: PFP: 0x016dd091, ME: 0x00000000
2021-11-17 08:11:11.876 27921-27921/com.twtech.twelveqa D/MediaBrowserCompat: Connecting to a MediaBrowserService.
2021-11-17 08:11:11.929 27921-27921/com.twtech.twelveqa I/TextToSpeech: Sucessfully bound to com.google.android.tts
2021-11-17 08:11:11.945 27921-27921/com.twtech.twelveqa D/PathProviderPlugin: Don't use TaskQueues.
2021-11-17 08:11:11.957 27921-27921/com.twtech.twelveqa I/TextToSpeech: Connected to ComponentInfo{com.google.android.tts/com.google.android.apps.speech.tts.googletts.service.GoogleTTSService}
2021-11-17 08:11:11.965 27921-27968/com.twtech.twelveqa I/TextToSpeech: Set up connection to ComponentInfo{com.google.android.tts/com.google.android.apps.speech.tts.googletts.service.GoogleTTSService}
2021-11-17 08:11:11.980 27921-27921/com.twtech.twelveqa W/System.err: java.lang.Exception
2021-11-17 08:11:11.980 27921-27921/com.twtech.twelveqa W/System.err:     at com.ryanheise.audioservice.AudioServicePlugin.getFlutterEngine(AudioServicePlugin.java:68)
2021-11-17 08:11:11.981 27921-27921/com.twtech.twelveqa W/System.err:     at com.ryanheise.audioservice.AudioService.onCreate(AudioService.java:282)
2021-11-17 08:11:11.981 27921-27921/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.handleCreateService(ActivityThread.java:4390)
2021-11-17 08:11:11.981 27921-27921/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.access$2000(ActivityThread.java:274)
2021-11-17 08:11:11.981 27921-27921/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2123)
2021-11-17 08:11:11.981 27921-27921/com.twtech.twelveqa W/System.err:     at android.os.Handler.dispatchMessage(Handler.java:106)
2021-11-17 08:11:11.981 27921-27921/com.twtech.twelveqa W/System.err:     at android.os.Looper.loop(Looper.java:233)
2021-11-17 08:11:11.981 27921-27921/com.twtech.twelveqa W/System.err:     at android.app.ActivityThread.main(ActivityThread.java:8030)
2021-11-17 08:11:11.981 27921-27921/com.twtech.twelveqa W/System.err:     at java.lang.reflect.Method.invoke(Native Method)
2021-11-17 08:11:11.981 27921-27921/com.twtech.twelveqa W/System.err:     at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:631)
2021-11-17 08:11:11.981 27921-27921/com.twtech.twelveqa W/System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:978)
2021-11-17 08:11:12.001 27921-27921/com.twtech.twelveqa I/TextToSpeech: Sucessfully bound to com.google.android.tts
2021-11-17 08:11:12.003 27921-27921/com.twtech.twelveqa D/PathProviderPlugin: Don't use TaskQueues.
2021-11-17 08:11:12.004 27921-27921/com.twtech.twelveqa I/System.out: flutterEngine warmed up
2021-11-17 08:11:12.010 27921-27921/com.twtech.twelveqa E/TTS: getDefaultLocale: Attempt to invoke virtual method 'java.util.Locale android.speech.tts.Voice.getLocale()' on a null object reference
2021-11-17 08:11:12.010 27921-27921/com.twtech.twelveqa I/TextToSpeech: Connected to ComponentInfo{com.google.android.tts/com.google.android.apps.speech.tts.googletts.service.GoogleTTSService}
2021-11-17 08:11:12.024 27921-27968/com.twtech.twelveqa I/TextToSpeech: Set up connection to ComponentInfo{com.google.android.tts/com.google.android.apps.speech.tts.googletts.service.GoogleTTSService}
2021-11-17 08:11:12.030 27921-27921/com.twtech.twelveqa E/TTS: getDefaultLocale: Attempt to invoke virtual method 'java.util.Locale android.speech.tts.Voice.getLocale()' on a null object reference
2021-11-17 08:11:12.138 27921-28006/com.twtech.twelveqa I/flutter: Observatory listening on http://127.0.0.1:42937/wP8DT2U-Uns=/
2021-11-17 08:11:12.945 27921-27921/com.twtech.twelveqa I/FLTFireMsgService: FlutterFirebaseMessagingBackgroundService started!
2021-11-17 08:11:13.007 27921-27987/com.twtech.twelveqa I/flutter: MessageHandler got: {authorProfileImageUrl: users/1094/profile/dee5cf5d-f7cc-4aaa-b058-61ffbcde1cd5.jpg, authorUserId: 1094, notificationContext: ForYouFeed, feedId: 68830, text: Is this working?, title: testing this one}
2021-11-17 08:11:13.601 27921-28018/com.twtech.twelveqa D/Choreographer: initialValue myPid:27921 myTid:28018 choreographer:android.view.Choreographer@eea5f84
2021-11-17 08:11:13.603 27921-27921/com.twtech.twelveqa W/twtech.twelveq: Accessing hidden method Landroid/media/AudioTrack;->getLatency()I (greylist, reflection, allowed)
2021-11-17 08:11:13.608 27921-27921/com.twtech.twelveqa I/ExoPlayerImpl: Init 6fd136d [ExoPlayerLib/2.15.0] [OnePlus8T, KB2003, OnePlus, 30]
2021-11-17 08:11:13.630 27921-27921/com.twtech.twelveqa I/TetheringManager: registerTetheringEventCallback:com.twtech.twelveqa
2021-11-17 08:11:13.632 27921-28011/com.twtech.twelveqa I/FirebaseApp: Device unlocked: initializing all Firebase APIs for app Twelve
2021-11-17 08:11:13.655 27921-28026/com.twtech.twelveqa E/sqlite3_android: ONEPLUS_NAME_PARTS_MATCH SQLITE_OK
2021-11-17 08:11:13.706 27921-28007/com.twtech.twelveqa I/flutter: FirebaseMessaging requestPermission error: [firebase_messaging/unknown] Attempt to invoke virtual method 'java.lang.Object android.content.Context.getSystemService(java.lang.String)' on a null object reference
2021-11-17 08:11:13.753 27921-28007/com.twtech.twelveqa I/flutter: Cloud Messaging Token is cvYJNS1zS4O_Ca6lCDfNsr:APA91bGdXwChgYtbpsFV99NMvaehdOIPHIFUsFSvLAseTCow8L0DPSfZu7hehLC9z_fMY8ypyD6MG-83PgUYVjGze0bLJC_mlJ6zVWOuenfyrGwC4HTMWU6iAv5wrC7YAuol3JQEJr4n
2021-11-17 08:11:13.759 27921-28007/com.twtech.twelveqa I/flutter: Application fully loaded!
2021-11-17 08:11:13.760 27921-27921/com.twtech.twelveqa W/FLTFireMsgService: Attempted to start a duplicate background isolate. Returning...
2021-11-17 08:11:16.031 27921-28027/com.twtech.twelveqa I/DpmTcmClient: RegisterTcmMonitor from: $Proxy1
2021-11-17 08:11:17.362 27921-28021/com.twtech.twelveqa W/VideoCapabilities: Unsupported mime image/vnd.android.heic
2021-11-17 08:11:17.374 27921-28021/com.twtech.twelveqa W/VideoCapabilities: Unrecognized profile/level 0/3 for video/mpeg2
2021-11-17 08:11:17.376 27921-28021/com.twtech.twelveqa W/VideoCapabilities: Unrecognized profile/level 0/3 for video/mpeg2
2021-11-17 08:11:17.508 27921-28034/com.twtech.twelveqa D/CCodec: allocate(c2.android.mp3.decoder)
2021-11-17 08:11:17.510 27921-28034/com.twtech.twelveqa I/Codec2Client: Available Codec2 services: "software"
2021-11-17 08:11:17.515 27921-28034/com.twtech.twelveqa I/CCodec: Created component [c2.android.mp3.decoder]
2021-11-17 08:11:17.516 27921-28034/com.twtech.twelveqa D/CCodecConfig: read media type: audio/mpeg
2021-11-17 08:11:17.518 27921-28034/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.max-count.values
2021-11-17 08:11:17.518 27921-28034/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: output.subscribed-indices.values
2021-11-17 08:11:17.518 27921-28034/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: input.buffers.allocator-ids.values
2021-11-17 08:11:17.518 27921-28034/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.allocator-ids.values
2021-11-17 08:11:17.519 27921-28034/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.allocator-ids.values
2021-11-17 08:11:17.519 27921-28034/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: output.buffers.pool-ids.values
2021-11-17 08:11:17.519 27921-28034/com.twtech.twelveqa D/ReflectedParamUpdater: extent() != 1 for single value type: algo.buffers.pool-ids.values
2021-11-17 08:11:17.520 27921-28034/com.twtech.twelveqa I/CCodecConfig: query failed after returning 7 values (BAD_INDEX)
2021-11-17 08:11:17.520 27921-28034/com.twtech.twelveqa D/CCodecConfig: c2 config diff is Dict {
      c2::u32 coded.bitrate.value = 64000
      c2::u32 input.buffers.max-size.value = 8192
      c2::u32 input.delay.value = 0
      string input.media-type.value = "audio/mpeg"
      string output.media-type.value = "audio/raw"
      c2::u32 raw.channel-count.value = 2
      c2::u32 raw.sample-rate.value = 44100
    }
2021-11-17 08:11:17.521 27921-28034/com.twtech.twelveqa D/CCodec: [c2.android.mp3.decoder] buffers are bound to CCodec for this session
2021-11-17 08:11:17.521 27921-28034/com.twtech.twelveqa D/CCodecConfig: no c2 equivalents for flags
2021-11-17 08:11:17.522 27921-28034/com.twtech.twelveqa D/CCodecConfig: config failed => CORRUPTED
2021-11-17 08:11:17.522 27921-28034/com.twtech.twelveqa W/Codec2Client: query -- param skipped: index = 1107298332.
2021-11-17 08:11:17.522 27921-28034/com.twtech.twelveqa D/CCodec: client requested max input size 4096, which is smaller than what component recommended (8192); overriding with component recommendation.
2021-11-17 08:11:17.522 27921-28034/com.twtech.twelveqa W/CCodec: This behavior is subject to change. It is recommended that app developers double check whether the requested max input size is in reasonable range.
2021-11-17 08:11:17.522 27921-28034/com.twtech.twelveqa D/CCodec: setup formats input: AMessage(what = 0x00000000) = {
      int32_t channel-count = 2
      int32_t max-input-size = 8192
      string mime = "audio/mpeg"
      int32_t sample-rate = 44100
    } and output: AMessage(what = 0x00000000) = {
      int32_t channel-count = 2
      string mime = "audio/raw"
      int32_t sample-rate = 44100
    }
2021-11-17 08:11:17.523 27921-28034/com.twtech.twelveqa W/Codec2Client: query -- param skipped: index = 1342179345.
2021-11-17 08:11:17.523 27921-28034/com.twtech.twelveqa W/Codec2Client: query -- param skipped: index = 2415921170.
2021-11-17 08:11:17.524 27921-28034/com.twtech.twelveqa E/FMQ: grantorIdx must be less than 3
2021-11-17 08:11:17.524 27921-28034/com.twtech.twelveqa E/FMQ: grantorIdx must be less than 3
2021-11-17 08:11:17.524 27921-28034/com.twtech.twelveqa D/CCodecBufferChannel: [c2.android.mp3.decoder#509] Created input block pool with allocatorID 16 => poolID 17 - OK (0)
2021-11-17 08:11:17.525 27921-28034/com.twtech.twelveqa I/CCodecBufferChannel: [c2.android.mp3.decoder#509] Created output block pool with allocatorID 16 => poolID 1100 - OK
2021-11-17 08:11:17.526 27921-28034/com.twtech.twelveqa D/CCodecBufferChannel: [c2.android.mp3.decoder#509] Configured output block pool ids 1100 => OK
2021-11-17 08:11:17.526 27921-28034/com.twtech.twelveqa E/ion: ioctl c0044901 failed with code -1: Inappropriate ioctl for device
2021-11-17 08:11:17.536 27921-28034/com.twtech.twelveqa E/FMQ: grantorIdx must be less than 3
2021-11-17 08:11:17.539 27921-28038/com.twtech.twelveqa E/FMQ: grantorIdx must be less than 3
2021-11-17 08:11:18.553 27921-28021/com.twtech.twelveqa D/AudioTrack: set(): streamType -1, sampleRate 44100, format 0x1, channelMask 0x3, frameCount 14144, flags #0, notificationFrames 0, sessionId 4345, transferType 3, uid -1, pid -1
2021-11-17 08:11:18.566 27921-28021/com.twtech.twelveqa D/AudioTrack: Uid 10928 AudioTrack::setVolume left 1.000000 right 1.000000
2021-11-17 08:11:22.692 27921-28037/com.twtech.twelveqa D/BufferPoolAccessor2.0: bufferpool2 0x7c43d17698 : 5(40960 size) total buffers - 4(32768 size) used buffers - 0/5 (recycle/alloc) - 7/38 (fetch/transfer)
2021-11-17 08:11:22.692 27921-28037/com.twtech.twelveqa D/BufferPoolAccessor2.0: evictor expired: 1, evicted: 1

Note that the callstack appears once.

yanivshaked avatar Nov 17 '21 06:11 yanivshaked

Sorry I understand what is going on now, and this is by design, not contrary to the API documentation. Still, your minimal reproduction project was helpful.

There are two things going on here:

  1. The audio handler is warming up so that it is ready to take requests from your background isolate (in this case the one created by firebase_messaging).
  2. The audio handler is hosted by the main isolate.

I take it that you don't want your app to perform some kind of complete initialisation in that warm up process. I think what happens in this situation is that the app widget is laid out with an effective size of 0x0 so it would be possible to wrap your app in a widget that waits until the dimension is greater than 0x0 before triggering the initialisation.

Down the track I might consider configuration options to run the audio handler in a separate isolate (again) or provide an option to prevent audio service loading in a particular background isolate but most people will not want that, and I think for now you can make your app work within the current model.

ryanheise avatar Nov 17 '21 07:11 ryanheise

@ryanheise, thank you for your quick response.

The issue is not only that the application is initialized in the warm up process; Its initialized incorrectly, ending up to be stuck on the application splash screen. (This is not reproduced by the example).

Is it possible (for us, in a forked version of audio_service), to recognize that the warm up process is originated from a push notification and not run the warm up process? Alternatively, if you can guide me, I am willing to submit a PR for providing an option to prevent the audio service from loading in a particular background isolate.

This is quite critical for us, as we are on the verge of releasing a new version of our application (pending this issue to be solved).

yanivshaked avatar Nov 17 '21 08:11 yanivshaked

Is it possible (for us, in a forked version of audio_service), to recognize that the warm up process is originated from a push notification and not run the warm up process?

Yes, I suggested the solution in my previous comment which is to look at the widget dimensions.

ryanheise avatar Nov 17 '21 08:11 ryanheise

I believe this solution is not sufficient for us, since when started in the background our application is stuck on the splash screen.

We need to recognize this situation before flutter UI is started, and prevent main activity from running.

yanivshaked avatar Nov 17 '21 09:11 yanivshaked

Do you mean the splash screen in your Flutter UI or in the Android XML layout?

ryanheise avatar Nov 17 '21 09:11 ryanheise

Splash screen of Android XML layout

yanivshaked avatar Nov 17 '21 09:11 yanivshaked

I'll need a repro project for that.

ryanheise avatar Nov 17 '21 09:11 ryanheise

Unfortunately this issue isn't reproduced on the example application, only on our application. I can try to assemble a repro for that, but I don't think this is the correct way to solve our issue.

yanivshaked avatar Nov 17 '21 09:11 yanivshaked

I would be interested in whatever is the quickest solution at this stage, whatever that turns out to be, but first I will need the repro case to work it out.

ryanheise avatar Nov 17 '21 09:11 ryanheise

I would like to contact you on your email to further discuss. If possible, please provide your email.

yanivshaked avatar Nov 17 '21 09:11 yanivshaked

My email is linked from my pub page.

ryanheise avatar Nov 17 '21 11:11 ryanheise

I have managed to find a working hack:

  1. Added a new method to AudioServicePlugin called setArmStartup, to control a private boolean flag:
    private static boolean armStartup = false;
    public static synchronized void setArmStartup(boolean enabled) {
        armStartup = enabled;
    }
  1. I have conditioned the operation of creating a new FlutterEngine by that flag:
    public static synchronized FlutterEngine getFlutterEngine(Context context) {
        if (armStartup == false) {
            return null;
        }
        FlutterEngine flutterEngine = FlutterEngineCache.getInstance().get(flutterEngineId);
        if (flutterEngine == null) {
            // XXX: The constructor triggers onAttachedToEngine so this variable doesn't help us.
            // Maybe need a boolean flag to tell us we're currently loading the main flutter engine.
            flutterEngine = new FlutterEngine(context.getApplicationContext());
            flutterEngine.getDartExecutor().executeDartEntrypoint(DartExecutor.DartEntrypoint.createDefault());
            FlutterEngineCache.getInstance().put(flutterEngineId, flutterEngine);
        }
        return flutterEngine;
    }
  1. I have added a call to setArmFlag under AudioServiceActivity.provideFlutterEngine:
public class AudioServiceActivity extends FlutterActivity {
    @Override
    public FlutterEngine provideFlutterEngine(Context context) {
        AudioServicePlugin.setArmStartup(true);
        return AudioServicePlugin.getFlutterEngine(context);
    }
}

In other words, I am not allowing the initialization of the flutter engine if application was not started from its main activity. You can view the code changed here.

What do you think?

yanivshaked avatar Nov 17 '21 13:11 yanivshaked

This would make the FlutterActivity to create its own engine which would break the plugin.

I tried reproducing the bug with the example you provided, but it didn't happen. It just received the notification regularly, and I was able to launch the app from it.

Also I would be interested to know how are you getting logs from a fully terminated app? I tried logcatting it, but it shows nothing.

nt4f04uNd avatar Nov 17 '21 13:11 nt4f04uNd

This would make the FlutterActivity to create its own engine which would break the plugin.

I have just retested the behavior of the application (with those changes incorporated into the audio_service plugin), and it seems to be working fine. Able to play from background, and application doesn't start on incoming FCM push notification.

I tried reproducing the bug with the example you provided, but it didn't happen. It just received the notification regularly, and I was able to launch the app from it.

The problem presented in the example is that after terminating the application, an incoming FCM push notification causes the application to fully launch in the background (which is NOT the wanted behavior). So when you say you were able to launch it - it was already running and you just put it into foreground.

Also I would be interested to know how are you getting logs from a fully terminated app? I tried logcatting it, but it shows nothing.

I am using Android Studio Logcat terminal while setting the debug com package to my own package: image

yanivshaked avatar Nov 17 '21 13:11 yanivshaked

Ok thanks.

This would make the FlutterActivity to create its own engine which would break the plugin.

Actually, I misread what this was doing, sorry, it should work fine however other apps also won't be able to run the service without an activity.

nt4f04uNd avatar Nov 17 '21 14:11 nt4f04uNd

Just to add my thoughts here for now, the main place to look is inside AudioServicePlugin.onAttachedToEngine which gets called on each plugin to install that plugin into each new FlutterEngine. Since firebase_messaging creates its own background FlutterEngine, this method will be called here to install audio_service into that engine. Now in audio_service, each FlutterEngine is set up to be a client of AudioService so that it can communicate with your audio handler. You don't want that, so you would need to edit this method to avoid connecting to the service in your specific case. If you want to do it with a boolean flag, the safer way to do it is not to set a flag for when you want to connect to the AudioService, but rather set a flag for when you "don't" want to connect to the AudioService. That is because there are more cases where the AudioService can and should be started from the background and you don't want to break those - there's only "one" situation where you actually want to disable the normal behaviour, so I would suggest setting your flag to handle that special case.

ryanheise avatar Nov 17 '21 14:11 ryanheise

Just to add my thoughts here for now, the main place to look is inside AudioServicePlugin.onAttachedToEngine which gets called on each plugin to install that plugin into each new FlutterEngine. Since firebase_messaging creates its own background FlutterEngine, this method will be called here to install audio_service into that engine. Now in audio_service, each FlutterEngine is set up to be a client of AudioService so that it can communicate with your audio handler. You don't want that, so you would need to edit this method to avoid connecting to the service in your specific case. If you want to do it with a boolean flag, the safer way to do it is not to set a flag for when you want to connect to the AudioService, but rather set a flag for when you "don't" want to connect to the AudioService. That is because there are more cases where the AudioService can and should be started from the background and you don't want to break those - there's only "one" situation where you actually want to disable the normal behaviour, so I would suggest setting your flag to handle that special case.

Understood. I will try going in that direction. In any case, this type of solution is a kind of hack (which will not be incorporated into the audio_service plugin), and I would like to pursue a proper solution that can be merged to the upstream.

yanivshaked avatar Nov 17 '21 15:11 yanivshaked

Hi! Just wanted to mention, that this conversation was useful when we were analyzing issues in our app.

What we have in our case is: install the app with Bluetooth turned off, then turn BT on without running the app (AudioService.onCreate calls AudioServicePlugin.getFlutterEngine with flutterEngine warmed up log message) and starting app after that causes it to stuck on splash screen.

I wonder if it may be caused by not calling onAttachedToEngine during the Activity startup (maybe because it was called on service onCreate when BT was turned on). May it be cached or something like that or maybe wrong flutter engine was initialized as you discussed above? Or because system keeps service alive?

Because on the second run app works fine and according to logs onAttachedToEngine is called during startup.

First I ended up with not calling AudioServicePlugin.getFlutterEngine in service onCreate, but saw this solutions, which is probably more elegant although in our case does pretty much the same.

In addition, I should mention that this behavior happens only on some devices (Samsung and OnePlus) and OS version (e.g. LineageOS 17.1) and may be related to some kind of vendor specific implementation of Android APIs.

tinted-knight avatar Dec 10 '21 13:12 tinted-knight

@tinted-knight is it feasible to provide a reproduction project for your particular case?

ryanheise avatar Dec 10 '21 14:12 ryanheise

I may have time to work on it during weekend. Also I made fixes that mentioned above based on yours from this issue that are already in minor (it looks important in our case not to have those crashes).

tinted-knight avatar Dec 10 '21 14:12 tinted-knight

The minor release has also been published.

ryanheise avatar Dec 10 '21 14:12 ryanheise

Hi,

We were facing the exact same issue as @yanivshaked and the dimension check with LayoutBuilder in main function seems to fix this for us. Thanks for suggesting this @ryanheise! I think FCM and audio_service issue should have a better fix for the long term though. Will the recommendation suggested #845 resolve the incorrect warming up issue as well?

mayurdhurpate avatar May 26 '22 11:05 mayurdhurpate

@mayurdhurpate Can you please share a code snippet of how you achieved that with LayoutBuilder in the main function

Adamteh avatar Jun 27 '22 14:06 Adamteh

I've added this in our main.dart:

void main() async {
  // ...some initialization code
  await runZonedGuarded<Future<void>>(() async {
    runApp(
      LayoutBuilder(builder: (context, constraints) {
        if (constraints.maxHeight == 0.0 && constraints.maxWidth == 0.0) {
          return Container();
        } else {
          return MyApp();
        }
      }),
    );
  }, (dynamic e, StackTrace st) {
    print(e);
    print(st);
    FirebaseCrashlytics.instance.recordError(e, st);
  });
}

In our case, we just wanted to prevent triggering of many analytics functions, and this solved the problem for us.

mayurdhurpate avatar Jun 28 '22 06:06 mayurdhurpate

Hi folks, Actually, I spent about 2 weeks trying on this issue, I wasted a lot of my time trying to figure out a solution. Today I find out that the problem is between the firebase messaging and audio service plugins. I tried the layout builder hack and it works. Thanks for adding this hack solution. But there is still an error when receiving the notification in the background, and the app is terminated, I hope for the coming days to have the solution added in the plugin concerning the layout builder hack but in other solution as checking the background service type running and also avoid having such an error in the background.

The error is as: E/flutter (20457): [ERROR:flutter/lib/ui/ui_dart_state.cc(198)] Unhandled Exception: [firebase_messaging/unknown] Attempt to invoke virtual method 'java.lang.Object android.content.Context.getSystemService(java.lang.String)' on a null object reference E/flutter (20457): E/flutter (20457): #0 StandardMethodCodec.decodeEnvelope (package:flutter/src/services/message_codecs.dart:607) E/flutter (20457): #1 MethodChannel._invokeMethod (package:flutter/src/services/platform_channel.dart:167) E/flutter (20457): E/flutter (20457): #2 MethodChannel.invokeMapMethod (package:flutter/src/services/platform_channel.dart:367) E/flutter (20457): E/flutter (20457): #3 MethodChannelFirebaseMessaging.requestPermission (package:firebase_messaging_platform_interface/src/method_channel/method_channel_messaging.dart:271) E/flutter (20457): E/flutter (20457): #4 main.. (package:gradeheroapp/main.dart:82) E/flutter (20457): E/flutter (

Thanks in advance,

AliShehab93 avatar Jul 15 '22 22:07 AliShehab93