getIds() big delay

[matheusrufinos]

Description: I need to get the player id. For this, I used the method getIds() -Ionic 4 Angular, but it takes 30 seconds to 3 minutes to return the data. It takes the same amount of time to register the device in the OneSignal dashboard.

Environment

Ionic:

ionic (Ionic CLI) : 4.12.0 (/Users/matheus/npm-global/lib/node_modules/ionic) Ionic Framework : @ionic/angular 4.0.0 @angular-devkit/build-angular : 0.12.4 @angular-devkit/schematics : 7.2.4 @angular/cli : 7.2.4 @ionic/angular-toolkit : 1.3.0

Cordova:

cordova (Cordova CLI) : 9.0.0 Cordova Platforms : android 8.0.0, browser 6.0.0, ios 5.0.1

System:

Android SDK Tools : 26.1.1 NodeJS : v11.9.0 npm : 6.8.0 OS : macOS Mojave Xcode : Xcode 10.2.1 Build version 10E1001

Steps to Reproduce Issue:

1. Create Ionic 4 Angular project; 2. Install the OneSignal via npm and the OneSignal Cordova plugin; 3. Perform the initial configuration of OneSignal with the id and sender id (firebase); 4. Add the OneSignal to the constructor (angular) and call the function to get ids (this.oneSignal.getIds().then((ids) =>{});

Thank you!

[rgomezp]

Could you please use the logging method to generate a log that may give us some further insights?

Same issue: https://stackoverflow.com/questions/56480715/ionic-4-onesignal-getids-big-delay

[matheusrufinos]

Hello! Thank you, I did not know this method. I do not know if I did it correctly, so I am sending some images of the information popups that appeared.

I did the test on the simulator (Android Studio), the popups were very fast and registered the device in less than 4 seconds. Very good, was the expected result.

However, after I tested it on a physical device, the popups were not fast and there was apparently no device registration.

I do not know if this helps to solve the problem, if not, can you guide me how to do this debug with the logging method correctly?

-- EDIT Also appeared a warning in Android Studio: The onsignal-gradle-plugin MUST be before com.android.application!

I decided to wait a little longer for a physical device, it returned me more of these popups:

After 3 minutes, device is registered, but I have this warn:

Thank you for your attention!

[rgomezp]

Try setting the logLevel to 6 and the visualLevel to 0 so that we only get the logs in the Android Studio logs instead of the messages on the device.

[matheusrufinos]

I do not know if that's exactly what I needed, but I got to see some problems with OneSignal, apparently something with the network, is that it? And after some time ends up registering the device correctly.

2019-06-19 11:37:42.904 31781-18060/? E/ctxmgr: [AppIntervalImpl] closeInterval: ongoing [CONTEXT service_id=47 ] 2019-06-19 11:37:42.952 31781-17919/? I/Places: ?: PlacesBleScanner stop() 2019-06-19 11:37:42.955 18090-18105/? I/AdapterState: BLE_TURNING_OFF : entered 2019-06-19 11:37:42.957 18090-18108/? I/bt_stack_manager: event_shut_down_stack is bringing down the stack 2019-06-19 11:37:42.957 18090-18108/? I/bt_btif_core: btif_disable_bluetooth entered 2019-06-19 11:37:42.957 18090-18140/? W/bt_osi_thread: run_thread: thread id 18140, thread name btif_sock exited 2019-06-19 11:37:42.957 18090-18136/? E/bt_btif: bta_jv_disable 2019-06-19 11:37:42.958 18090-18108/? I/bt_btif_core: btif_disable_bluetooth finished 2019-06-19 11:37:42.958 18090-18136/? W/bt_btif: bta_dm_disable BTA_DISABLE_DELAY set to 200 ms 2019-06-19 11:37:42.958 18090-18108/? I/bt_core_module: module_shut_down Shutting down module "btif_config_module" 2019-06-19 11:37:42.962 31781-17919/? I/PlaceInferenceEngine: [anon] Changed inference mode: 0 2019-06-19 11:37:42.962 31781-17919/? I/PlaceInferenceEngine: [account#-361562193] Changed inference mode: 0 2019-06-19 11:37:42.962 31781-31781/? I/BeaconBle: 'L' hardware scan: scan stopped, no clients 2019-06-19 11:37:42.963 31781-31781/? I/BeaconBle: Places requested to stop scan 2019-06-19 11:37:42.963 31781-31781/? I/BeaconBle: Scan canceled successfully. 2019-06-19 11:37:43.004 31781-31781/? I/GeofencerStateMachine: removeGeofences: removeRequest=RemoveGeofencingRequest[REMOVE_BY_PENDING_INTENT pendingIntent=PendingIntent[creatorPackage=com.google.android.gms], packageName=com.google.android.gms] 2019-06-19 11:37:43.015 31781-32172/? W/MessageQueue: Handler (aeus) {94ec6f8} sending message to a Handler on a dead thread java.lang.IllegalStateException: Handler (aeus) {94ec6f8} sending message to a Handler on a dead thread at android.os.MessageQueue.enqueueMessage(MessageQueue.java:546) at android.os.Handler.enqueueMessage(Handler.java:745) at android.os.Handler.sendMessageAtTime(Handler.java:697) at aeus.sendMessageAtTime(Unknown Source:3) at android.os.Handler.sendMessageDelayed(Handler.java:667) at android.os.Handler.post(Handler.java:395) at bcgo.execute(Unknown Source:2) at avam.a(:com.google.android.gms@17455039@17.4.55 (100408-248795830):3) at avaz.a(:com.google.android.gms@17455039@17.4.55 (100408-248795830):6) at avbg.a(:com.google.android.gms@17455039@17.4.55 (100408-248795830):43) at avbc.a(:com.google.android.gms@17455039@17.4.55 (100408-248795830):2) at rfc.a(:com.google.android.gms@17455039@17.4.55 (100408-248795830):3) at rfc.a(:com.google.android.gms@17455039@17.4.55 (100408-248795830):2) at agla.a(Unknown Source:2) at rdp.a(Unknown Source:11) at aabo.a(:com.google.android.gms@17455039@17.4.55 (100408-248795830):1) at cum.onTransact(:com.google.android.gms@17455039@17.4.55 (100408-248795830):4) at android.os.Binder.execTransact(Binder.java:731) 2019-06-19 11:37:43.046 18090-18108/? I/bt_core_module: module_shut_down Shutdown of module "btif_config_module" completed 2019-06-19 11:37:43.135 18345-18345/com.b3appdev.ch I/chromium: [INFO:CONSOLE(52621)] "Angular is running in the development mode. Call enableProdMode() to enable the production mode.", source: http://localhost/vendor.js (52621) 2019-06-19 11:37:43.159 18090-18114/? I/bt_btif_core: btif_disable_bluetooth_evt entered 2019-06-19 11:37:43.159 18090-18114/? I/bt_core_module: module_shut_down Shutting down module "hci_module" 2019-06-19 11:37:43.160 18090-18114/? I/bt_hci: hci_module_shut_down 2019-06-19 11:37:43.160 18090-18114/? I/bt_hci: hci_close 2019-06-19 11:37:43.160 567-567/? W/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::close() 2019-06-19 11:37:43.160 567-567/? I/vendor.qti.bluetooth@1.0-data_handler: Sending HCI Reset 2019-06-19 11:37:43.236 567-18134/? W/vendor.qti.bluetooth@1.0-data_handler: OnPacketReady: Received event for command sent internally: 03 0c 2019-06-19 11:37:43.237 567-567/? W/vendor.qti.bluetooth@1.0-data_handler: DataHandler::CleanUp() 2019-06-19 11:37:43.237 567-567/? I/vendor.qti.bluetooth@1.0-data_handler: DataHandler:: init_status 3 2019-06-19 11:37:43.237 567-567/? W/vendor.qti.bluetooth@1.0-async_fd_watcher: StopThread: stopped the work thread 2019-06-19 11:37:43.237 567-567/? I/vendor.qti.bluetooth@1.0-mct_transport: CleanUp:> soc_type: 0 2019-06-19 11:37:43.272 18345-18345/com.b3appdev.ch I/chromium: [INFO:CONSOLE(128083)] "Ionic Native: deviceready event fired after 3927 ms", source: http://localhost/vendor.js (128083) 2019-06-19 11:37:43.328 18345-18440/com.b3appdev.ch I/OneSignal: Restoring notifications 2019-06-19 11:37:43.351 18345-18440/com.b3appdev.ch I/OneSignal: Querying DB for notifs to restore: created_time > 1560350263 AND dismissed = 0 AND opened = 0 AND is_summary = 0 AND expire_time > 1560955063 2019-06-19 11:37:43.386 18345-18433/com.b3appdev.ch W/PluginManager: THREAD WARNING: exec() call to OneSignalPush.init blocked the main thread for 80ms. Plugin should use CordovaInterface.getThreadPool(). 2019-06-19 11:37:43.387 18345-18444/com.b3appdev.ch I/DpmTcmClient: RegisterTcmMonitor from: com.android.okhttp.TcmIdleTimerMonitor 2019-06-19 11:37:43.530 567-567/? W/vendor.qti.bluetooth@1.0-data_handler: controller Cleanup done 2019-06-19 11:37:43.530 567-567/? I/vendor.qti.bluetooth@1.0-data_handler: DataHandler:: joined Init thread 2019-06-19 11:37:43.530 567-567/? W/vendor.qti.bluetooth@1.0-bluetooth_hci: BluetoothHci::close, finish cleanup 2019-06-19 11:37:43.531 18090-18130/? W/bt_osi_thread: run_thread: thread id 18130, thread name hci_thread exited 2019-06-19 11:37:43.531 18090-18114/? I/bt_core_module: module_shut_down Shutdown of module "hci_module" completed 2019-06-19 11:37:43.532 18090-18114/? I/bt_core_module: module_shut_down Shutting down module "btsnoop_module" 2019-06-19 11:37:43.532 18090-18114/? I/bt_core_module: module_shut_down Shutdown of module "btsnoop_module" completed 2019-06-19 11:37:43.532 18090-18114/? I/bt_core_module: module_clean_up Cleaning up module "bte_logmsg_module" 2019-06-19 11:37:43.532 18090-18114/? I/bt_core_module: module_clean_up Cleanup of module "bte_logmsg_module" completed 2019-06-19 11:37:43.533 18090-18135/? W/bt_osi_thread: run_thread: thread id 18135, thread name bt_workqueue exited 2019-06-19 11:37:43.533 18090-18114/? I/bt_btif_core: btif_disable_bluetooth_evt finished 2019-06-19 11:37:43.534 18090-18108/? I/bt_core_module: module_shut_down Shutting down module "controller_module" 2019-06-19 11:37:43.534 18090-18108/? I/bt_core_module: module_shut_down Shutdown of module "controller_module" completed 2019-06-19 11:37:43.535 18090-18108/? I/bt_stack_manager: event_shut_down_stack finished 2019-06-19 11:37:43.537 18090-18090/? W/bt_btif: GATTC Module not enabled/already disabled 2019-06-19 11:37:43.537 18090-18090/? W/bt_btif: GATTS Module not enabled/already disabled 2019-06-19 11:37:43.539 18090-18090/? W/BluetoothAdapterService: onProfileServiceStateChange() - All profile services stopped.. 2019-06-19 11:37:43.540 18090-18105/? I/AdapterState: OFF : entered 2019-06-19 11:37:43.543 18090-18090/? W/BluetoothAdapterService: onUnbind, calling cleanup 2019-06-19 11:37:43.552 18090-18090/? W/BluetoothSdpJni: Cleaning up Bluetooth SDP Interface... 2019-06-19 11:37:43.552 18090-18090/? W/BluetoothSdpJni: Cleaning up Bluetooth SDP object 2019-06-19 11:37:43.552 18090-18108/? I/bt_stack_manager: event_clean_up_stack is cleaning up the stack 2019-06-19 11:37:43.552 18090-18108/? I/bt_btif_core: btif_cleanup_bluetooth entered 2019-06-19 11:37:43.552 18090-18108/? E/BluetoothServiceJni: Callback: 'callback_thread_event' is not called on the correct thread 2019-06-19 11:37:43.552 18090-18108/? I/bt_btif_queue: btif_queue_release 2019-06-19 11:37:43.552 18090-18114/? I/bt_btif_core: run_message_loop finished 2019-06-19 11:37:43.553 18090-18114/? W/bt_osi_thread: run_thread: thread id 18114, thread name bt_jni_workqueue exited 2019-06-19 11:37:43.553 18090-18108/? I/bt_core_module: module_clean_up Cleaning up module "stack_config_module" 2019-06-19 11:37:43.553 18090-18108/? I/bt_core_module: module_clean_up Cleanup of module "stack_config_module" completed 2019-06-19 11:37:43.554 18090-18108/? I/bt_core_module: module_clean_up Cleaning up module "interop_module" 2019-06-19 11:37:43.622 18090-18108/? I/bt_core_module: module_clean_up Cleanup of module "interop_module" completed 2019-06-19 11:37:43.622 18090-18108/? I/bt_core_module: module_clean_up Cleaning up module "profile_config_module" 2019-06-19 11:37:43.622 18090-18108/? I/bt_core_module: module_clean_up Cleanup of module "profile_config_module" completed 2019-06-19 11:37:43.622 18090-18108/? I/bt_btif_core: btif_cleanup_bluetooth finished 2019-06-19 11:37:43.622 18090-18108/? I/bt_core_module: module_clean_up Cleaning up module "btif_config_module" 2019-06-19 11:37:43.647 31802-18351/? I/GmsTraceSample: 5ms performing 45-xlb -> AsyncOpTask -> AsyncOpImpl [0,5% sampled, 206 omitted, module=security__nonwearable, caller=null] 2019-06-19 11:37:43.668 18090-18108/? I/bt_core_module: module_clean_up Cleanup of module "btif_config_module" completed 2019-06-19 11:37:43.668 18090-18108/? I/bt_core_module: module_clean_up Cleaning up module "bt_utils_module" 2019-06-19 11:37:43.668 18090-18108/? I/bt_core_module: module_clean_up Cleanup of module "bt_utils_module" completed 2019-06-19 11:37:43.668 18090-18108/? I/bt_core_module: module_clean_up Cleaning up module "osi_module" 2019-06-19 11:37:43.669 18090-18113/? W/bt_osi_thread: run_thread: thread id 18113, thread name alarm_dispatcher exited 2019-06-19 11:37:43.669 18090-18112/? W/bt_osi_thread: run_thread: thread id 18112, thread name alarm_default_ca exited 2019-06-19 11:37:43.670 18090-18108/? I/bt_core_module: module_clean_up Cleanup of module "osi_module" completed 2019-06-19 11:37:43.670 18090-18108/? I/bt_stack_manager: event_clean_up_stack finished 2019-06-19 11:37:43.670 18090-18090/? I/BluetoothServiceJni: cleanupNative: return from cleanup 2019-06-19 11:37:43.671 18090-18090/? W/BluetoothVendorJni: Cleaning up Bluetooth Vendor Interface... 2019-06-19 11:37:43.671 18090-18090/? I/bt_btif_vendor: cleanup 2019-06-19 11:37:43.671 18090-18090/? W/BluetoothVendorJni: Cleaning up Bluetooth Vendor callback object 2019-06-19 11:37:43.671 18090-18090/? W/BluetoothVendorSocketJni: Cleaning up Bluetooth Vendor Interface... 2019-06-19 11:37:43.671 18090-18090/? I/bt_btif_vendorsocket: cleanup 2019-06-19 11:37:43.671 18090-18090/? W/BluetoothVendorSocketJni: Cleaning up Bluetooth Vendor callback object 2019-06-19 11:37:43.672 18345-18345/com.b3appdev.ch I/chromium: [INFO:CONSOLE(1238)] "first get ids: ", source: http://localhost/main.js (1238) 2019-06-19 11:37:43.675 18090-18090/? I/BluetoothAdapterService: Force exit to cleanup internal state in Bluetooth stack 2019-06-19 11:37:43.678 18090-18090/? I/droid.bluetoot: System.exit called, status: 0 2019-06-19 11:37:43.678 18090-18090/? I/AndroidRuntime: VM exiting with result code 0, cleanup skipped. 2019-06-19 11:37:43.701 1736-5399/? I/ActivityManager: Process com.android.bluetooth (pid 18090) has died: fore SVC 2019-06-19 11:37:43.701 1736-1754/? W/libprocessgroup: kill(-18090, 9) failed: No such process 2019-06-19 11:37:43.701 1736-1754/? I/libprocessgroup: Successfully killed process cgroup uid 1002 pid 18090 in 0ms 2019-06-19 11:37:43.702 834-834/? I/Zygote: Process 18090 exited cleanly (0) 2019-06-19 11:37:44.157 18345-18433/com.b3appdev.ch I/App: WARNING: Back Button Default Behavior will be overridden. The backbutton event will be fired! 2019-06-19 11:37:46.169 24367-18300/? W/Analytics-Core-ConfigServer: HttpResponse is empty 2019-06-19 11:37:47.880 15774-15804/? I/WorkerManager: dispose() 2019-06-19 11:37:47.880 15774-15804/? W/ThreadPoolDumper: Queue length for executor EventBus is now 11. Perhaps some tasks are too long, or the pool is too small. 2019-06-19 11:37:47.980 31781-31781/? I/BeaconBle: 'L' hardware scan: scan stopped, no clients 2019-06-19 11:37:51.134 17740-17740/? I/Finsky: [2] com.google.android.finsky.scheduler.JobSchedulerEngine$PhoneskyJobSchedulerJobService.onStartJob(3): onJobSchedulerWakeup with jobId 9000 2019-06-19 11:37:51.141 17740-17740/? I/Finsky: [2] pvd.a(21): Scheduling fallback job with id: 9034, and delay: 43200000 ms 2019-06-19 11:37:51.148 17740-17740/? I/Finsky: [2] pvd.a(5): Scheduling fallback in 64799996 (absolute: 2048079628) 2019-06-19 11:37:51.190 17740-17740/? I/Finsky: [2] pvn.handleMessage(10): DeviceState: DeviceState{currentTime=1560955071183, isCharging=true, isIdle=false, netAny=true, netNotRoaming=true, netUnmetered=true} 2019-06-19 11:37:51.202 17740-18286/? I/Finsky: [1660] pxb.b(7): Jobs in database: 1-1337 10-1 10-3 10-4 10-6 10-7 10-8 10-10 10-11 10-12 10-14 10-15 10-16 10-18 10-20 10-22 10-24 10-25 10-26 10-27 10-28 10-29 10-30 10-31 10-33 10-35 10-36 10-38 10-39 10-40 10-41 10-42 10-44 10-46 10-47 10-48 10-50 10-54 10-55 10-57 10-61 12-1 26-1414141414 2019-06-19 11:37:51.207 17740-17740/? I/Finsky: [2] pvk.a(22): Running job: 12-1 2019-06-19 11:37:51.208 17740-17740/? I/Finsky: [2] com.google.android.finsky.contentsync.ContentSyncJob.a(22): ContentSyncJob started 2019-06-19 11:37:51.208 17740-17740/? I/Finsky: [2] pvn.handleMessage(84): RunningQueue size: 1, PendingQueue size: 0 2019-06-19 11:37:51.209 17740-17740/? I/Finsky: [2] pvn.handleMessage(93): Running queue: 12-1 2019-06-19 11:37:51.338 17740-18457/? I/Finsky: [1663] dkl.a(5): Completed 0 account content syncs with 0 successful. 2019-06-19 11:37:51.338 17740-17740/? I/Finsky: [2] com.google.android.finsky.contentsync.ContentSyncJob.a(20): Installation state replication succeeded. 2019-06-19 11:37:51.338 17740-17740/? I/Finsky: [2] pwy.a(9): jobFinished: 12-1. TimeElapsed: 131ms 2019-06-19 11:37:51.339 17740-17740/? I/Finsky: [2] pvk.c(3): Job 12-1 finished 2019-06-19 11:37:51.339 17740-17740/? I/Finsky: [2] pvn.handleMessage(84): RunningQueue size: 0, PendingQueue size: 0 2019-06-19 11:37:51.340 17740-17740/? I/Finsky: [2] pvn.handleMessage(27): Executor finished 2019-06-19 11:37:51.362 17740-17740/? I/Finsky: [2] pxb.b(7): Jobs in database: 1-1337 10-1 10-3 10-4 10-6 10-7 10-8 10-10 10-11 10-12 10-14 10-15 10-16 10-18 10-20 10-22 10-24 10-25 10-26 10-27 10-28 10-29 10-30 10-31 10-33 10-35 10-36 10-38 10-39 10-40 10-41 10-42 10-44 10-46 10-47 10-48 10-50 10-54 10-55 10-57 10-61 26-1414141414 2019-06-19 11:37:51.364 17740-17740/? I/Finsky: [2] pui.a(113): ConstraintMapping: 1-1337, 10-1, 10-3, 10-4, 10-6, 10-7, 10-8, 10-10, 10-11, 10-12, 10-14, 10-15, 10-16, 10-18, 10-20, 10-22, 10-24, 10-25, 10-26, 10-27, 10-28, 10-29, 10-30, 10-31, 10-33, 10-35, 10-36, 10-38, 10-39, 10-40, 10-41, 10-42, 10-44, 10-46, 10-47, 10-48, 10-50, 10-54, 10-55, 10-57, 10-61, -> L: 33864560ms, D: 77064560ms, C: false, I: false, N: 1 2019-06-19 11:37:51.365 17740-17740/? I/Finsky: [2] pui.a(113): ConstraintMapping: 26-1414141414, -> L: 26355463ms, D: 27255463ms, C: false, I: false, N: 0 2019-06-19 11:37:51.366 17740-17740/? I/Finsky: [2] com.google.android.finsky.scheduler.JobSchedulerEngine.a(42): Cancelling existing job with id: 9003 2019-06-19 11:37:51.368 17740-17740/? I/Finsky: [2] com.google.android.finsky.scheduler.JobSchedulerEngine.a(4): Scheduling job Id: 9001, L: 33864560, D: 77064560, C: false, I: false, N: 1 2019-06-19 11:37:51.371 17740-17740/? I/Finsky: [2] com.google.android.finsky.scheduler.JobSchedulerEngine.a(4): Scheduling job Id: 9002, L: 26355463, D: 27255463, C: false, I: false, N: 0 2019-06-19 11:37:54.124 1736-5399/? W/ActivityManager: Background start not allowed: service Intent { cmp=com.google.android.apps.messaging/.shared.datamodel.action.execution.ActionExecutorImpl$EmptyService } to com.google.android.apps.messaging/.shared.datamodel.action.execution.ActionExecutorImpl$EmptyService from pid=17313 uid=10080 pkg=com.google.android.apps.messaging startFg?=false 2019-06-19 11:37:54.126 17313-17313/? W/BugleDataModel: ActionExecutorImpl: Action started execution, but we can't guarantee it will complete, the app may be killed. Action: class com.google.android.apps.messaging.shared.datamodel.action.SelfParticipantsRefreshAction-SelfParticipantsRefreshAction:1983162417005 java.lang.IllegalStateException: Not allowed to start service Intent { cmp=com.google.android.apps.messaging/.shared.datamodel.action.execution.ActionExecutorImpl$EmptyService }: app is in background uid UidRecord{c304198 u0a80 CEM idle change:cached procs:2 seq(0,0,0)} at android.app.ContextImpl.startServiceCommon(ContextImpl.java:1577) at android.app.ContextImpl.startService(ContextImpl.java:1532) at android.content.ContextWrapper.startService(ContextWrapper.java:664) at com.google.android.apps.messaging.shared.datamodel.action.execution.ActionExecutorImpl.a(SourceFile:21) at com.google.android.apps.messaging.shared.datamodel.action.execution.ActionExecutorImpl.a(SourceFile:17) at efs.c(SourceFile:12) at efr.run(Unknown Source:1) at android.os.Handler.handleCallback(Handler.java:873) at android.os.Handler.dispatchMessage(Handler.java:99) at android.os.Looper.loop(Looper.java:193) at android.app.ActivityThread.main(ActivityThread.java:6694) at java.lang.reflect.Method.invoke(Native Method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858) 2019-06-19 11:37:54.130 17313-17447/? I/BugleDataModel: ParticipantRefresh: Start participant refresh. refreshMode: 1 2019-06-19 11:37:54.181 17313-17447/? W/Bugle: SubscriptionMetadataUtils get: invalid subId = -1 2019-06-19 11:37:54.183 17313-17447/? I/chatty: uid=10080(com.google.android.apps.messaging) BackgroundThrea identical 1 line 2019-06-19 11:37:54.185 17313-17447/? W/Bugle: SubscriptionMetadataUtils get: invalid subId = -1 2019-06-19 11:37:54.186 17313-17447/? E/Bugle: Get mms config failed: invalid subId. subId=-1, real subId=-1, map={ } 2019-06-19 11:37:54.187 17313-17447/? I/BugleBackup: Registering preference change listener for "buglesub-1". 2019-06-19 11:37:54.191 17313-17447/? W/Bugle: SubscriptionUtilsPostLMR1: getSelfRawNumber: subInfo is null for subscription{id:-1} 2019-06-19 11:37:54.401 17313-17447/? I/BugleDataModel: ParticipantRefresh: Number of participants refreshed: 1 2019-06-19 11:37:56.414 17313-17313/? W/BugleDataModel: ActionExecutorImpl: Action started execution, but we can't guarantee it will complete, the app may be killed. Action: class com.google.android.apps.messaging.shared.datamodel.action.GenericWorkerQueueAction-GenericWorkerQueueAction:1983162417011 java.lang.IllegalStateException: Not allowed to start service Intent { cmp=com.google.android.apps.messaging/.shared.datamodel.action.execution.ActionExecutorImpl$EmptyService }: app is in background uid UidRecord{c304198 u0a80 CEM idle change:cached procs:2 seq(0,0,0)} at android.app.ContextImpl.startServiceCommon(ContextImpl.java:1577) at android.app.ContextImpl.startService(ContextImpl.java:1532) at android.content.ContextWrapper.startService(ContextWrapper.java:664) at com.google.android.apps.messaging.shared.datamodel.action.execution.ActionExecutorImpl.a(SourceFile:21) at com.google.android.apps.messaging.shared.datamodel.action.execution.ActionExecutorImpl.a(SourceFile:17) at efs.c(SourceFile:12) at efr.run(Unknown Source:1) at android.os.Handler.handleCallback(Handler.java:873) at android.os.Handler.dispatchMessage(Handler.java:99) at android.os.Looper.loop(Looper.java:193) at android.app.ActivityThread.main(ActivityThread.java:6694) at java.lang.reflect.Method.invoke(Native Method) at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493) at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858) 2019-06-19 11:37:56.412 1736-5399/? W/ActivityManager: Background start not allowed: service Intent { cmp=com.google.android.apps.messaging/.shared.datamodel.action.execution.ActionExecutorImpl$EmptyService } to com.google.android.apps.messaging/.shared.datamodel.action.execution.ActionExecutorImpl$EmptyService from pid=17313 uid=10080 pkg=com.google.android.apps.messaging startFg?=false 2019-06-19 11:37:57.948 1736-5399/? I/ActivityManager: Killing 16746:com.google.android.dialer/u0a34 (adj 906): empty #17 2019-06-19 11:37:57.950 1736-1754/? W/libprocessgroup: kill(-16746, 9) failed: No such process 2019-06-19 11:37:57.981 835-835/? I/Zygote: Process 16746 exited due to signal (9) 2019-06-19 11:37:57.995 1736-1754/? W/libprocessgroup: kill(-16746, 9) failed: No such process 2019-06-19 11:37:57.995 1736-1754/? I/libprocessgroup: Successfully killed process cgroup uid 10034 pid 16746 in 46ms 2019-06-19 11:38:12.357 849-925/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0 2019-06-19 11:38:12.917 15774-17083/? W/GmsLocationProvider: Error removing location updates: 16 2019-06-19 11:38:26.336 2361-2373/? I/ndroid.systemu: Background concurrent copying GC freed 355093(12MB) AllocSpace objects, 0(0B) LOS objects, 61% free, 7MB/19MB, paused 257us total 103.180ms 2019-06-19 11:38:36.751 31802-18351/? W/gle.android.gm: resources.arsc in APK '/data/app/com.duapps.recorder-aHJEcl-cWpgDgJvxzj2cmw==/base.apk' is compressed. 2019-06-19 11:38:36.830 31802-18471/? I/AppsUpload: Uploading list of 33 apps for 1 account(s) 2019-06-19 11:38:36.842 31802-18471/? E/AppsUpload: Privacy bit setting explicitly disabled 2019-06-19 11:38:38.977 896-2904/? I/LOWI-8.6.0.31: [LOWI-Scan] lowi_close_record:Scan done in 1983258390ms, 5 APs in scan results 2019-06-19 11:38:57.176 31781-14256/? E/WakeLock: GCM_HB_ALARM release without a matched acquire! 2019-06-19 11:39:12.359 849-925/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0 2019-06-19 11:39:20.709 1736-2308/? I/Nat464Xlat: Android Xlat is disabled 2019-06-19 11:39:20.716 2501-2501/? I/DPMJ: |SERVICE| sendWifiStatus - subType: 21 networkState: 1 softApState: 11 rssi=0 ssid= bssid=00:00:00:00:00:00 ipV4Addr= ifNameV4= ipAddrV6= ifNameV6= 2019-06-19 11:39:20.734 17513-17584/? I/CarrierServices: [11984] cdh.a: FiST: Wifi connectivity status true 2019-06-19 11:39:20.735 17513-17584/? I/CarrierServices: [11984] cdk.d: Connected state: [1], networkType: [WIFI] 2019-06-19 11:39:58.068 17740-17758/? I/Finsky: [1587] iku.run(3): Stats for Executor: BlockingExecutor imd@2ff1b6[Running, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 19] 2019-06-19 11:39:58.069 17740-17758/? I/Finsky: [1587] iku.run(3): Stats for Executor: LightweightExecutor imd@8d38eb7[Running, pool size = 4, active threads = 0, queued tasks = 0, completed tasks = 61] 2019-06-19 11:39:58.277 17740-17758/? I/Finsky: [1587] iku.run(3): Stats for Executor: bgExecutor imd@19b624[Running, pool size = 4, active threads = 0, queued tasks = 0, completed tasks = 43] 2019-06-19 11:40:03.274 896-2904/? I/LOWI-8.6.0.31: [LOWI-Scan] lowi_close_record:Scan done in 1983342687ms, 4 APs in scan results 2019-06-19 11:40:12.361 849-925/? E/storaged: getDiskStats failed with result NOT_SUPPORTED and size 0 2019-06-19 11:40:19.033 18345-18444/com.b3appdev.ch W/OneSignal: OneSignalRestClient: null Error thrown from network stack. java.io.InterruptedIOException: thread interrupted at com.android.okhttp.okio.Timeout.throwIfReached(Timeout.java:145) at com.android.okhttp.okio.Okio$1.write(Okio.java:73) at com.android.okhttp.okio.AsyncTimeout$1.write(AsyncTimeout.java:155) at com.android.okhttp.okio.RealBufferedSink.flush(RealBufferedSink.java:221) at com.android.okhttp.internal.http.Http1xStream.finishRequest(Http1xStream.java:161) at com.android.okhttp.internal.http.HttpEngine.readNetworkResponse(HttpEngine.java:735) at com.android.okhttp.internal.http.HttpEngine.readResponse(HttpEngine.java:609) at com.android.okhttp.internal.huc.HttpURLConnectionImpl.execute(HttpURLConnectionImpl.java:471) at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getResponse(HttpURLConnectionImpl.java:407) at com.android.okhttp.internal.huc.HttpURLConnectionImpl.getResponseCode(HttpURLConnectionImpl.java:538) at com.android.okhttp.internal.huc.DelegatingHttpsURLConnection.getResponseCode(DelegatingHttpsURLConnection.java:105) at com.android.okhttp.internal.huc.HttpsURLConnectionImpl.getResponseCode(HttpsURLConnectionImpl.java:26) at com.onesignal.OneSignalRestClient.startHTTPConnection(OneSignalRestClient.java:169) at com.onesignal.OneSignalRestClient.access$100(OneSignalRestClient.java:42) at com.onesignal.OneSignalRestClient$4.run(OneSignalRestClient.java:104) at java.lang.Thread.run(Thread.java:764) 2019-06-19 11:40:19.037 18345-18486/com.b3appdev.ch I/OneSignal: Failed to get Android parameters, trying again in 30 seconds. 2019-06-19 11:40:42.770 1736-1745/? I/system_server: Background concurrent copying GC freed 436432(17MB) AllocSpace objects, 18(680KB) LOS objects, 42% free, 21MB/37MB, paused 429us total 280.958ms 2019-06-19 11:40:49.385 18345-18498/com.b3appdev.ch I/OneSignal: Device registered, push token = cuv5dejSti8:APA91bE6e2eR3MS6keVdAg7qOSMeWRDFQWMO4ddxQqBcNCzkjUgqfhlEkKkky8ALu-vWqPMLWeyzm6fexbVcY-44LBDqckMpFSTlBb63gkJcUkJhdEpIVoXTqPk4iKCty1KybV7DUF1d 2019-06-19 11:40:49.627 1736-1753/? I/ActivityManager: Start proc 18504:com.android.chrome:privileged_process1/u0a76 for service com.android.chrome/org.chromium.content.app.PrivilegedProcessService1 2019-06-19 11:40:49.638 18504-18504/? E/ileged_process: Not starting debugger since process cannot load the jdwp agent. 2019-06-19 11:40:49.642 1736-1753/? I/ActivityManager: Start proc 18512:com.android.chrome:sandboxed_process1/u0i157 for webview_service com.android.chrome/org.chromium.content.app.SandboxedProcessService1 2019-06-19 11:40:49.649 18512-18512/? E/dboxed_process: Not starting debugger since process cannot load the jdwp agent. 2019-06-19 11:40:49.686 18504-18504/? W/ileged_process: JIT profile information will not be recorded: profile file does not exits. 2019-06-19 11:40:49.701 18504-18504/? I/Perf: Connecting to perf service. 2019-06-19 11:40:49.714 18512-18512/? I/cr_ChildProcessService: Creating new ChildProcessService pid=18512 2019-06-19 11:40:49.723 18504-18504/? I/cr_ChildProcessService: Creating new ChildProcessService pid=18504 2019-06-19 11:40:49.726 18512-18533/? I/cr_LibraryLoader: Time to load native libraries: 0 ms (timestamps 3696-3696) 2019-06-19 11:40:49.727 18512-18533/? I/chromium: [INFO:library_loader_hooks.cc(50)] Chromium logging enabled: level = 0, default verbosity = 0 2019-06-19 11:40:49.728 18512-18533/? I/cr_LibraryLoader: Expected native library version number "75.0.3770.89", actual native library version number "75.0.3770.89" 2019-06-19 11:40:49.731 1736-2486/? I/ActivityManager: Killing 17449:com.google.android.apps.messaging:rcs/u0a80 (adj 906): empty #17 2019-06-19 11:40:49.732 1736-1754/? W/libprocessgroup: kill(-17449, 9) failed: No such process 2019-06-19 11:40:49.770 18504-18534/? I/cr_LibraryLoader: Time to load native libraries: 4 ms (timestamps 3736-3740) 2019-06-19 11:40:49.771 18504-18534/? I/chromium: [INFO:library_loader_hooks.cc(50)] Chromium logging enabled: level = 0, default verbosity = 0 2019-06-19 11:40:49.772 18504-18534/? I/cr_LibraryLoader: Expected native library version number "75.0.3770.89", actual native library version number "75.0.3770.89" 2019-06-19 11:40:49.778 1736-1754/? W/libprocessgroup: kill(-17449, 9) failed: No such process 2019-06-19 11:40:49.791 18504-18534/? I/Adreno: QUALCOMM build : 2df12b3, I07da2d9908 Build Date : 10/04/18 OpenGL ES Shader Compiler Version: EV031.25.03.01 Local Branch : Remote Branch : Remote Branch : Reconstruct Branch : 2019-06-19 11:40:49.791 18504-18534/? I/Adreno: Build Config : S L 6.0.7 AArch32 2019-06-19 11:40:49.795 18504-18534/? I/Adreno: PFP: 0x005ff110, ME: 0x005ff066 2019-06-19 11:40:49.796 834-834/? I/Zygote: Process 17449 exited due to signal (9)

[rgomezp]

I see. The problem is here:

2019-06-19 11:40:19.037 18345-18486/com.b3appdev.ch I/OneSignal: Failed to get Android parameters, trying again in 30 seconds.
2019-06-19 11:40:42.770 1736-1745/? I/system_server: Background concurrent copying GC freed 436432(17MB) AllocSpace objects, 18(680KB) LOS objects, 42% free, 21MB/37MB, paused 429us total 280.958ms
2019-06-19 11:40:49.385 18345-18498/com.b3appdev.ch I/OneSignal: Device registered, push token = cuv5dejSti8:AP

This just looks like a bad network connection. Make sure you have a solid connection while running your tests.

[matheusrufinos]

Understand. I believe that the internet connection is good, 60mb of download and 6MB of upload (this in Brazil, São Paulo-SP and Santos-SP). This problem happens in the tests in France (Paris) also, where the download is of 100mb with 10mb upload. Would there be any other reason for this connection error with OneSignal? Apparently other plugins and https calls (backend api for example) are normal, no problems.

Thank you very much for your attention and help!

[rgomezp]

There's no other reason for the error except bad network :/ No problem!