search

invertase / react-native-firebase

🔥 A well-tested feature-rich modular Firebase implementation for React Native. Supports both iOS & Android platforms for all Firebase services.
https://rnfirebase.io
Other
11.53k stars 2.18k forks source link

🔥[🐛] onMessage stops getting triggered after few messages on iOS #4603

Closed jeremycod closed 3 years ago

jeremycod commented 3 years ago

Issue

Describe your issue here

I'm using @react-native-firebase/messaging: 10.0.0 together with react-native-push-notifications: 6.1.3 to send push notifications from node.js backend. It seems to be working on Android without problems, but on iOS I'm having a problem to make it working when app is in foreground. onMessage is getting triggered few times and it stops working. If I send application to background, those messages are coming, but returning it back to foreground doesn't help in that case.

My message payload looks like this:

{
   data: {
     createdAt: 'Tue Nov 24 2020 05:12:45 GMT+0000 (Coordinated Universal Time)',
     notificationType: 'NewRx',
     badge: 'warning',
     itemId: '5fb1b6380843b1a25a8276c9',
     title: 'Your order is on hold',
     body: 'Your order is on hold'
   },
   notification: {
     title: 'Your order is on hold',
     body: 'Your order is on hold',
     sound: 'default'
   }
 }

In addition I'm sending these two options: contentAvailable: true, priority: 'high' On the backend I'm receiving success message. Any suggestions what might be wrong? Is there anything like 'adb logcat' for iPhone that could give me more logs?

Project Files

Javascript

Click To Expand

#### `package.json`: ```json { "name": "FillRxMobile", "version": "1.0.0", "private": false, "scripts": { "start": "react-native start", "dev": "NODE_ENV=docker react-native start", "test": "jest", "test:update": "jest -u", "test:coverage": "jest --coverage", "run:ios": "ENVFILE=.env.docker react-native run-ios", "run:android": "ENVFILE=.env.docker react-native run-android", "lint": "./node_modules/eslint/bin/eslint.js src", "lint:fix": "./node_modules/eslint/bin/eslint.js src --fix", "flow": "./node_modules/flow-bin/cli.js", "e2e:build": "detox build --configuration ios.sim.debug", "e2e:test": "detox test --configuration ios.sim.debug", "postinstall": "npx jetify update:pods", "devtools": "react-devtools", "update:pods": "cd ios && pod install --repo-update && cd .. && patch-package", "clean-react-native": "watchman watch-del-all && rm -rf node_modules && yarn install && rm -rf /tmp/metro-bundler-cache-* && yarn start -- --reset-cache && rm -rf /tmp/haste-map-react-native-packager-*" }, "dependencies": { "@babel/polyfill": "^7.12.1", "@breeffy/react-native-popup-menu": "^0.8.0", "@react-native-community/blur": "^3.6.0", "@react-native-community/datetimepicker": "^3.0.4", "@react-native-community/masked-view": "^0.1.10", "@react-native-community/netinfo": "^5.9.7", "@react-native-community/picker": "^1.8.1", "@react-native-community/push-notification-ios": "^1.7.5-beta.0", "@react-native-firebase/app": "^10.0.0", "@react-native-firebase/auth": "^10.0.0", "@react-native-firebase/messaging": "^10.0.0", "@react-navigation/bottom-tabs": "^5.11.1", "@react-navigation/drawer": "^5.11.2", "@react-navigation/native": "^5.8.9", "@react-navigation/stack": "^5.12.6", "axios": "^0.21.0", "date-fns": "^2.16.1", "gulp": "^4.0.2", "gulp-clean": "^0.4.0", "gulp-rename": "^2.0.0", "i18n-js": "^3.8.0", "immer": "^7.0.14", "jetifier": "^1.6.6", "jwt-decode": "^3.1.1", "libphonenumber-js": "^1.9.2", "lodash": "^4.17.20", "moment": "^2.29.1", "react": "^17.0.1", "react-devtools": "^4.9.0", "react-native": "0.63.3", "react-native-awesome-alerts": "^1.4.2", "react-native-calendars": "^1.403.0", "react-native-cli": "^2.0.1", "react-native-config": "^1.4.1", "react-native-dotenv": "^2.4.2", "react-native-dropdown-picker": "^3.7.1", "react-native-elements": "^2.3.2", "react-native-gesture-handler": "^1.8.0", "react-native-gifted-chat": "^0.16.3", "react-native-image-picker": "^2.3.4", "react-native-invoke-app": "^1.0.4", "react-native-keyboard-aware-scroll-view": "^0.9.3", "react-native-lightbox": "^0.8.0", "react-native-linear-gradient": "^2.5.6", "react-native-localize": "^1.4.3", "react-native-material-dropdown": "git+https://github.com/noway/react-native-material-dropdown.git", "react-native-modal-datetime-picker": "^9.0.0", "react-native-modal-selector": "^2.0.3", "react-native-phone-call": "^1.0.9", "react-native-push-notification": "^6.1.3", "react-native-reanimated": "^1.13.1", "react-native-safe-area-context": "^3.1.8", "react-native-screens": "^2.14.0", "react-native-snap-carousel": "^3.9.1", "react-native-splash-screen": "^3.2.0", "react-native-svg": "^12.1.0", "react-native-ui-lib": "^5.16.0", "react-native-vector-icons": "^7.1.0", "react-native-webview": "^10.10.2", "react-redux": "^7.2.2", "react-router": "^5.2.0", "react-router-dom": "^5.2.0", "react-uuid": "^1.0.2", "redux": "^4.0.1", "redux-logger": "^3.0.6", "redux-persist": "^6.0.0", "redux-saga": "^1.1.3", "redux-thunk": "^2.3.0", "socket.io": "^3.0.1", "socket.io-client": "^3.0.1", "use-state-with-callback": "^2.0.3", "yargs": "^16.1.0" }, "devDependencies": { "@babel/cli": "^7.12.1", "@babel/core": "^7.12.3", "@babel/preset-env": "^7.12.1", "@react-native-community/async-storage": "^1.12.1", "babel-eslint": "^10.0.1", "babel-jest": "^26.6.3", "babel-plugin-transform-inline-environment-variables": "^0.4.3", "danger": "^10.5.1", "enzyme": "^3.7.0", "enzyme-adapter-react-16": "^1.15.5", "eslint": "^7.13.0", "eslint-config-airbnb": "^18.2.1", "eslint-config-prettier": "^6.15.0", "eslint-plugin-import": "^2.22.1", "eslint-plugin-jsx-a11y": "^6.4.1", "eslint-plugin-react": "^7.21.5", "flow-bin": "^0.137.0", "jest": "^26.6.3", "metro-react-native-babel-preset": "^0.64.0", "react-dom": "^17.0.1" }, "jest": { "preset": "react-native", "transform": { "^.+\\.js$": "/node_modules/react-native/jest/preprocessor.js" }, "collectCoverage": true, "collectCoverageFrom": [ "src/**/*.{js,jsx}", "!**/node_modules/**", "!android/**", "!ios/**", "!assets/**" ], "coverageDirectory": "jest_coverage", "setupFiles": [ "./jest-setup.js" ], "testPathIgnorePatterns": [ "/node_modules/", "/e2e/" ] }, "rnpm": { "assets": [ "./assets/fonts/" ] }, "detox": { "configurations": { "ios.sim.debug": { "binaryPath": "ios/build/Build/Products/Debug-iphonesimulator/FillRxApp.app", "build": "xcodebuild -UseModernBuildSystem=NO -project ios/FillRxApp.xcodeproj -scheme FillRxApp -configuration Debug -sdk iphonesimulator -derivedDataPath ios/build", "type": "ios.simulator", "name": "iPhone XS" }, "ios.sim.release": { "binaryPath": "ios/build/Build/Products/Release-iphonesimulator/FillRxApp.app", "build": "xcodebuild -UseModernBuildSystem=NO -project ios/FillRxApp.xcodeproj -scheme FillRxApp -configuration Release -sdk iphonesimulator -derivedDataPath ios/build", "type": "ios.simulator", "name": "iPhone 7" } }, "test-runner": "jest" } } ``` #### `firebase.json` for react-native-firebase v6: ```json # N/A ```

iOS

Click To Expand

#### `ios/Podfile`: - [ ] I'm not using Pods - [x] I'm using Pods and my Podfile looks like: ```ruby pod 'Firebase/Core' pod 'Firebase/Auth' require_relative '../node_modules/@react-native-community/cli-platform-ios/native_modules' require_relative '../node_modules/react-native/scripts/react_native_pods' platform :ios, '10.0' target 'FillRxApp' do config = use_native_modules! use_react_native!(:path => config["reactNativePath"]) pod 'RNFBApp', :path => '../node_modules/@react-native-firebase/app' pod 'react-native-config', :path => '../node_modules/react-native-config' target 'FillRxAppTests' do inherit! :complete # Pods for testing end # Enables Flipper. # # Note that if you have use_frameworks! enabled, Flipper will not work and # you should disable these next few lines. use_flipper! post_install do |installer| flipper_post_install(installer) end end target 'FillRxApp-tvOS' do # Pods for FillRxApp-tvOS target 'FillRxApp-tvOSTests' do inherit! :search_paths # Pods for testing end end ``` #### `AppDelegate.m`: ```objc pod 'Firebase/Core' pod 'Firebase/Auth' require_relative '../node_modules/@react-native-community/cli-platform-ios/native_modules' require_relative '../node_modules/react-native/scripts/react_native_pods' platform :ios, '10.0' target 'FillRxApp' do config = use_native_modules! use_react_native!(:path => config["reactNativePath"]) pod 'RNFBApp', :path => '../node_modules/@react-native-firebase/app' pod 'react-native-config', :path => '../node_modules/react-native-config' target 'FillRxAppTests' do inherit! :complete # Pods for testing end # Enables Flipper. # # Note that if you have use_frameworks! enabled, Flipper will not work and # you should disable these next few lines. use_flipper! post_install do |installer| flipper_post_install(installer) end end target 'FillRxApp-tvOS' do # Pods for FillRxApp-tvOS target 'FillRxApp-tvOSTests' do inherit! :search_paths # Pods for testing end end ```

Android

Click To Expand

#### Have you converted to AndroidX? - [ ] my application is an AndroidX application? - [ ] I am using `android/gradle.settings` `jetifier=true` for Android compatibility? - [ ] I am using the NPM package `jetifier` for react-native compatibility? #### `android/build.gradle`: ```groovy // N/A ``` #### `android/app/build.gradle`: ```groovy // N/A ``` #### `android/settings.gradle`: ```groovy // N/A ``` #### `MainApplication.java`: ```java // N/A ``` #### `AndroidManifest.xml`: ```xml ```

Environment

Click To Expand

**`react-native info` output:** ``` OUTPUT GOES HERE ``` - **Platform that you're experiencing the issue on**: - [*] iOS - [ ] Android - [ ] **iOS** but have not tested behavior on Android - [ ] **Android** but have not tested behavior on iOS - [ ] Both - **`react-native-firebase` version you're using that has this issue:** - `10.0` - **`Firebase` module(s) you're using that has the issue:** - `messaging` - **Are you using `TypeScript`?** - `N` & `VERSION`

mikehardy commented 3 years ago

There is something like logcat: if you launch release mode on a real (plugged in to computer) iPhone from Xcode you get a nice console where all logging for the process goes - it's the best way to figure things out

jeremycod commented 3 years ago

Hi @mikehardy

I guess you meant the Logs console available under Window -> Devices and Simulator.

I could see this error there:

Screen Shot 2020-11-24 at 6 40 05 AM

Does it give you any idea?

Thanks

mikehardy commented 3 years ago

That is one way to see them yes, but I find that presentation awful (both the Console.app experience as a dev in general, and the pasting of any images into a bug report - I process text here, images are terrible for debugging)

Nothing there seems interesting

mikehardy commented 3 years ago

if you launch release mode on a real (plugged in to computer) iPhone from Xcode you get a nice console where all logging for the process goes - it's the best way to figure things out

jeremycod commented 3 years ago

Hi @mikehardy

Thank you for your quick feedback. I did some more testing and found that this issue happens only on 1 out of 3 iOS devices that I've used. It doesn't happen on iphone 6 and iphone 11 Pro Max I've used for testing, but it always happens on iPhone 11. When the issue happens if app is in the background Push Notifications are coming but messaging().setBackgroundMessageHandler is not triggered. If the application is in foreground messaging().onMessage is not triggered.

From the log, I can see that notifications are coming to the device, but except these kind of problem

No data found at /var/mobile/Library/UserNotifications/92ACF24C-D279-4B68-8F04-0DC04023F2DE/Categories.plist

I don't see any error. This is the log from device:

default 16:03:14.048561-0800    apsd    <private> hasPayload? <private> forTopic <private> tokens <private>
default 16:03:14.051687-0800    apsd    copyAppSpecificTokensWithDomain - sandbox.push.apple.com for topic <private> account <private>
default 16:03:14.051831-0800    apsd    <private> receivedPushWithTopic <private> token <private> payload <private> timestamp Tue Nov 24 16:03:13 2020
default 16:03:14.052207-0800    apsd    <private>: Received message for enabled topic '<private>' onInterface: NonCellular with payload '<private>' with priority 10 for device token: NO
default 16:03:14.053359-0800    apsd    <private> asked to store incoming message <private> with guid <private> environment <private>
default 16:03:14.054467-0800    apsd    APSMessageStore - New message record [<private>] has ID [5290].
default 16:03:14.054721-0800    apsd    <private>: Sending acknowledgement message with response 0 and messageId <private> (1614409838)
default 16:03:14.055234-0800    CommCenter  #I <private> request: <private>, expects reply.
default 16:03:14.055434-0800    CommCenter  #I <private> reply to request '<private>'.
default 16:03:14.056010-0800    apsd    <private> isLTEWithCDRX? Unknown  --  powerlog value 0
default 16:03:14.056391-0800    apsd    <private> _notifyForIncomingMessage <private> with guid <private>
default 16:03:14.058438-0800    apsd    <private>: Stream processing: complete yes, invalid no, length parsed 4, parameters <private>
default 16:03:14.058507-0800    apsd    <private>: Received keep-alive response 1 on interface NonCellular: <private>
default 16:03:14.058572-0800    apsd    Releasing power assertion {identifier: APSCourier(tcpStream:dataReceived:)}
default 16:03:14.061043-0800    apsd    Created power assertion {identifier: APSCourier(tcpStream:dataReceived:)}
default 16:03:14.062061-0800    apsd    <private>: Stream processing: complete no, invalid no, length parsed 0, parameters (null)
default 16:03:14.062355-0800    apsd    Created metric container: 0x130004 succeeded? YES
default 16:03:14.063108-0800    apsd    Dispatching high priority message on server: <private>
default 16:03:14.063899-0800    SpringBoard <private> Delivering message from apsd: <private> 1614409838 <private>
default 16:03:14.064069-0800    SpringBoard <private> making delegate (<private>) calls to deliver message 1614409838 <private> for topic <private>
default 16:03:14.064249-0800    SpringBoard <private> calling <private> connection:didReceiveIncomingMessage:
default 16:03:14.064331-0800    SpringBoard <private> returned from <private> connection:didReceiveIncomingMessage:
default 16:03:14.064538-0800    SpringBoard Received incoming message on topic org.reactjs.native.example.FillRxApp at priority 10
default 16:03:14.064603-0800    SpringBoard <private> responding with an ack for message with guid <private>
default 16:03:14.065135-0800    apsd    Looking up connection on peer: d3e210   found <private>
default 16:03:14.065182-0800    apsd    <private> informed that <private> acknowledges incoming message with guid <private> tracingUUID (null)
default 16:03:14.065574-0800    apsd    APSMessageStore - APSIncomingMessageRecordDeleteMessageForGUID <private>
default 16:03:14.076440-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Received remote notification request 5787-BB3C [ waking: 0, hasAlertContent: 1, hasSound: 1 hasBadge: 0 hasContentAvailable: 1 hasMutableContent: 0 pushType: Alert]
default 16:03:14.076519-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Process delivery of push notification 5787-BB3C
default 16:03:14.076570-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Request DUET delivers content-available push notification to application
default 16:03:14.076781-0800    SpringBoard Overwriting <private> with <private>
default 16:03:14.076837-0800    SpringBoard SUBMITTING: <private>
default 16:03:14.076884-0800    SpringBoard Establish daemon connection; interrupted: 0
error   16:03:14.077378-0800    SpringBoard No data found at /var/mobile/Library/UserNotifications/92ACF24C-D279-4B68-8F04-0DC04023F2DE/Categories.plist
error   16:03:14.077915-0800    SpringBoard No data found at /var/mobile/Library/UserNotifications/92ACF24C-D279-4B68-8F04-0DC04023F2DE/Categories.plist
default 16:03:14.077997-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Send willPresentNotification for notification 5787-BB3C
default 16:03:14.078094-0800    dasd    Please file a bug for <private> – the activity is running in a loop.
default 16:03:14.078542-0800    dasd    Submitted Activity: com.apple.pushLaunch.org.reactjs.native.example.FillRxApp:34A293 at priority 10 <private>
default 16:03:14.079898-0800    SpringBoard [FBSSystemService][0x70f8] Sending request to open "org.reactjs.native.example.FillRxApp"
default 16:03:14.080410-0800    dasd    Caching handle <private>, with ipc id 1802794900002122, and pid 8482
default 16:03:14.081940-0800    dasd    Adding a launch request (<private>) for application <private> by activity <private>
default 16:03:14.081988-0800    dasd    Launch requests for <private>: <private>
default 16:03:14.082039-0800    dasd    Daemon Canceling Activities: {(
    com.apple.pushLaunch.org.reactjs.native.example.FillRxApp:C40557
)}
default 16:03:14.082189-0800    dasd    CANCELED: com.apple.pushLaunch.org.reactjs.native.example.FillRxApp:C40557 at priority 10 <private>!
default 16:03:14.082319-0800    dasd    Removing a launch request for application <private> by activity <private>
default 16:03:14.085000-0800    dasd    With <private> ...Tasks pre-running in group [com.apple.dasd.defaultNetwork] are 1!
default 16:03:14.085159-0800    dasd    NO LONGER RUNNING [Not in application -> activity mapping] com.apple.pushLaunch.org.reactjs.native.example.FillRxApp:34A293 ...Tasks running in group [com.apple.dasd.defaultNetwork] are 0!
default 16:03:14.085438-0800    SpringBoard cancelActivities: 1 activities were not found: <private>
default 16:03:14.086040-0800    SpringBoard [FBSystemService][0x70f8] Received request to open "org.reactjs.native.example.FillRxApp" from SpringBoard:59.
default 16:03:14.086206-0800    SpringBoard [FBSystemService][0x70f8] Trusting entitled client SpringBoard:59.
default 16:03:14.086410-0800    SpringBoard Received trusted open application request for "org.reactjs.native.example.FillRxApp" from <FBApplicationProcess: 0x14080b4e0; daemon<com.apple.SpringBoard>:59(v87)>.
default 16:03:14.091092-0800    kernel  LQM-WiFi: (2G) rxCrsGlitch=177 rxBphyCrsGlitch=108 rxStart=131 rxBadPLCP=11 rxBphyBadPLCP=0 rxBadFCS=16 rxFifo0Ovfl=0 rxFifo1Ovfl=0 rx_nobuf=0 rxAnyErr=21 rxResponseTimeout=1 rxNoDelim=3 rxFrmTooLong=0 rxFrmTooShort=10
default 16:03:14.091135-0800    kernel  LQM-WiFi: (2G) txRTSFrm=0 txRTSFail=0 rxCTSUcast=0 rxRTSUcast=0 txCTSFrm=3 txAMPDU=0 rxBACK=0 txPhyError=0 txAllFrm=9 txMPDU=10 txUcast=5 rxACKUcast=3
default 16:03:14.091156-0800    kernel  LQM-WiFi: (2G)  rxBeaconMbss=48 rxBeaconObss=2 rxDataUcastMbss=1 rxMgmtUcastMbss=0 rxCNTRLUcast=3 txACKFrm=1 txBACK=0
default 16:03:14.091180-0800    kernel  LQM-WiFi: RX AMPDU (2G) rxAmpdu=0 txBACK(Ucode)=0 rxMpduInAmpdu=0 rxholes=0 rxdup=0 rxstuck=0 rxoow=0 rxoos=0 rxaddbareq=1 txaddbaresp=1 rxbar=0 txdelba=0 rxdelba=0 rxQueued=0
default 16:03:14.091198-0800    kernel  LQM-WiFi: chan 11 OfdmDesense 0dB
default 16:03:14.093113-0800    trustd  cert[0]: SubjectCommonName =(leaf)[]> 0
default 16:03:14.093296-0800    trustd  cert[0]: LeafMarkerOid =(leaf)[force]> 0
default 16:03:14.098351-0800    trustd  cert[0]: IssuerCommonName =(path)[]> 0
default 16:03:14.099040-0800    SpringBoard Trust evaluate failure: [leaf IssuerCommonName LeafMarkerOid SubjectCommonName]
default 16:03:14.099498-0800    wifid   Too frequent(0.165223 secs) rssi event from driver, ignoring
default 16:03:14.099540-0800    wifid   __WiFiDeviceManagerMonitor24GHzInfraNetworkTraffic: SNR 33.3, CCA 37.1, Tx bandwidth 48176.5 (kbps), Rx bandwidth 53529.2, Tx data rate 220.2 (kbps), Rx data rate  2106.8, Tx air time 0.457 %, Rx air time 3.936 %, Good background traffic ? No
default 16:03:14.099574-0800    wifid   __WiFiDeviceManagerEvaluate24GHzInfraNetworkState:isConnected Yes, isTimeSensitiveAppRunning No, isThereTrafficNow No
default 16:03:14.099632-0800    wifid   __WiFiLQAMgrLogStats(jeremic:Stationary): Rssi: -60 {-59 -67} Snr: 34 Cca: 37 (S:0 O:26 I:10) TxPer: 0.0% (7) BcnPer: 3.7% (54, 54.0%) RxFrms: 125 RxRetryFrames: 1 TxRate: 65000 RxRate: 144444 FBRate: 19500 TxFwFrms: 6 TxFwFail: 0 TxReTrans: 2 time: 53.7secs fgApp: org.reactjs.native.example.FillRxApp
default 16:03:14.099895-0800    wifid   WiFiLQAMgrCopyCoalescedUndispatchedLQMEvent: Rssi: -60 Snr:34 Cca: 37 TxFrames: 7 TxFail: 0 BcnRx: 52 BcnSch: 54  RxFrames: 125 RxRetries: 1 TxRate: 65000 RxRate: 144444 FBRate: 19500 TxFwFrms: 6 TxFwFail:0 TxRetries: 2
default 16:03:14.100209-0800    symptomsd   L2 Metrics on en0: rssi: -60 [-59,-67] -> -60, snr: 34 (cca [wake/total] self/other/intf): [0,0]/[0,0]/[0,0]/37 (txFrames/txReTx/txFail): 7/2/0 -> (was/is) 0/0
default 16:03:14.100253-0800    symptomsd   Received Wi-Fi Assist Override along with LQM info: 0
default 16:03:14.102286-0800    SpringBoard Executing request: <SBMainWorkspaceTransitionRequest: 0x2801522e0; eventLabel: OpenApplication(sceneID:org.reactjs.native.example.FillRxApp-default)ForRequester(SpringBoard.59); display: Main; source: FBSystemService>
default 16:03:14.102509-0800    SpringBoard Executing suspended-activation immediately: OpenApplication(sceneID:org.reactjs.native.example.FillRxApp-default)ForRequester(SpringBoard.59)
default 16:03:14.102814-0800    WirelessRadioManagerd   <private>
default 16:03:14.103523-0800    SpringBoard [FBSystemService][0x70f8] Request complete; no error reported.
default 16:03:14.103622-0800    WirelessRadioManagerd   <private>
default 16:03:14.103840-0800    WirelessRadioManagerd   <private>
default 16:03:14.103949-0800    WirelessRadioManagerd   <private>
default 16:03:14.104403-0800    SpringBoard [FBSSystemService][0x70f8] Request successful: <BSProcessHandle: 0x283fc4b40; FillRxApp:8482; valid: YES>
default 16:03:14.104526-0800    SpringBoard [org.reactjs.native.example.FillRxApp] willPresentNotification delivery succeeded for notification 5787-BB3C
default 16:03:14.104650-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Created process assertion for will present notification
default 16:03:14.105504-0800    runningboardd   Acquiring assertion targeting [application<org.reactjs.native.example.FillRxApp>:8482] from originator [daemon<com.apple.SpringBoard>:59] with description <RBSAssertionDescriptor| "will present notification" ID:32-59-90551 target:8482 attributes:[
    <RBSLegacyAttribute| requestedReason:NotificationAction reason:NotificationAction flags:( PreventTaskSuspend PreventThrottleDownUI )>,
    <RBSAcquisitionCompletionAttribute| policy:AfterValidation>
    ]>
default 16:03:14.106481-0800    runningboardd   Assertion 32-59-90551 (target:[application<org.reactjs.native.example.FillRxApp>:8482]) will be created as inactive as start-time-defining assertions exist
default 16:03:14.107197-0800    runningboardd   Finished acquiring assertion 32-59-90551 (target:[application<org.reactjs.native.example.FillRxApp>:8482])
default 16:03:14.108820-0800    wifid   Copy current network requested by "WirelessRadioMan"
default 16:03:14.111917-0800    wifid   Copy current network requested by "WirelessRadioMan"
default 16:03:14.113039-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Received response 0 for willPresentNotification for notification 5787-BB3C
default 16:03:14.113471-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Removing process assertion for will present notification
default 16:03:14.113794-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Badge can be set for notification 5787-BB3C: 0 [ canBadge: 0 badgeNumber: (null) ]
default 16:03:14.113919-0800    SpringBoard Getting effectiveSectionInfo for section identifier: org.reactjs.native.example.FillRxApp
default 16:03:14.114048-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Getting effective section info
default 16:03:14.114095-0800    SpringBoard Getting requested effective section info (sync)
default 16:03:14.114234-0800    runningboardd   Invalidating assertion 32-59-90551 (target:[application<org.reactjs.native.example.FillRxApp>:8482]) from originator [daemon<com.apple.SpringBoard>:59]
default 16:03:14.114428-0800    SpringBoard Got effective section info [ result: 0 ]
default 16:03:14.114463-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Got effective section info [ hasResult: 1 ]
default 16:03:14.114495-0800    SpringBoard Getting effectiveSectionInfo for section identifier: org.reactjs.native.example.FillRxApp
default 16:03:14.114528-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Getting effective section info
default 16:03:14.114558-0800    SpringBoard Getting requested effective section info (sync)
default 16:03:14.114655-0800    SpringBoard Got effective section info [ result: 0 ]
default 16:03:14.114686-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Got effective section info [ hasResult: 1 ]
default 16:03:14.114717-0800    SpringBoard [Persisting notification 5787-BB3C: 1 [applicableSettings: 1]
default 16:03:14.114749-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Saving notification 5787-BB3C: 0 [ hasAlertContent: 1, shouldPresentAlert: 0 ]
default 16:03:14.114780-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Delivered user visible push notification 5787-BB3C
error   16:03:14.115439-0800    SpringBoard No data found at /var/mobile/Library/UserNotifications/92ACF24C-D279-4B68-8F04-0DC04023F2DE/PendingNotifications.plist
default 16:03:14.115480-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Load 0 pending notification dictionaries
default 16:03:14.115537-0800    SpringBoard [org.reactjs.native.example.FillRxApp] Adding notification 5787-BB3C [ hasAlertContent: 1, shouldPresentAlert: 0 hasSound: 1 shouldPlaySound: 0 ]; destinations 256: (
    Forwarding
)
error   16:03:14.115624-0800    SpringBoard No data found at /var/mobile/Library/UserNotifications/92ACF24C-D279-4B68-8F04-0DC04023F2DE/Categories.plist
error   16:03:14.115767-0800    SpringBoard No data found at /var/mobile/Library/UserNotifications/92ACF24C-D279-4B68-8F04-0DC04023F2DE/Categories.plist
default 16:03:14.116034-0800    SpringBoard BBDataProviderProxy org.reactjs.native.example.FillRxApp has enqueued a bulletin request
default 16:03:14.116164-0800    SpringBoard BBDataProviderProxy org.reactjs.native.example.FillRxApp is now sending enqueued bulletin request to BBServer
default 16:03:14.116723-0800    SpringBoard BBDataProvider: Add bulletin to destinations 256: (
    Forwarding
)
default 16:03:14.117130-0800    SpringBoard Publishing bulletin for section <org.reactjs.native.example.FillRxApp>: subsectionIDs: (null), bulletinID = <482D9DE2-E74C-4F73-B484-112F99DF1C62>, expiration date = <Tue Dec  1 16:03:13 2020>, expiration events <0>
default 16:03:14.117373-0800    SpringBoard BBServer: Publish bulletin 482D9DE2-E74C-4F73-B484-112F99DF1C62 to feeds 1024: (
    Forwarding
)
default 16:03:14.117403-0800    SpringBoard request to find bulletin match: <private>
default 16:03:14.117434-0800    SpringBoard Request to check cache: <private>
default 16:03:14.117563-0800    SpringBoard 1 gateways found.
default 16:03:14.117594-0800    SpringBoard Sending to observers of gateway: <private>
default 16:03:14.117628-0800    SpringBoard Sending add bulletin with lights and sirens YES for transactionID 1, bulletin 482D9DE2-E74C-4F73-B484-112F99DF1C62
default 16:03:14.117679-0800    SpringBoard Sending add bulletin with lights and sirens YES for transactionID 1, bulletin 482D9DE2-E74C-4F73-B484-112F99DF1C62
default 16:03:14.118172-0800    SpringBoard Sending add bulletin with lights and sirens YES for transactionID 1, bulletin 482D9DE2-E74C-4F73-B484-112F99DF1C62
default 16:03:14.118508-0800    SpringBoard Bulletin with bulletinID <482D9DE2-E74C-4F73-B484-112F99DF1C62>, expiration date <Tue Dec  1 16:03:13 2020> inserted in expiring bulletins array at index 62
default 16:03:14.118563-0800    SpringBoard Next expire bulletins date = Tue Nov 24 16:45:00 2020; current fire date = Tue Nov 24 16:45:00 2020
default 16:03:14.118653-0800    SpringBoard Not adjusting expiration timer. Next fire date = Tue Nov 24 16:45:00 2020
default 16:03:14.118890-0800    SpringBoard Observer for NCBulletinNotificationSource: Delivering ADD bulletin: 482D9DE2-E74C-4F73-B484-112F99DF1C62
default 16:03:14.118951-0800    SpringBoard NCBulletinNotificationSource adding bulletin 5787-BB3C for feed 1024 in section org.reactjs.native.example.FillRxApp
default 16:03:14.119024-0800    SpringBoard Observer for SASBulletinManager: Delivering ADD bulletin: 482D9DE2-E74C-4F73-B484-112F99DF1C62
default 16:03:14.119091-0800    SpringBoard Unhandled BBObserver feed: 1024
default 16:03:14.119432-0800    assistantd  Observer for ADNotificationManager: Delivering ADD bulletin: 482D9DE2-E74C-4F73-B484-112F99DF1C62
default 16:03:14.147360-0800    SpringBoard Observer for SASBulletinManager: finished with bulletin 482D9DE2-E74C-4F73-B484-112F99DF1C62, transactionID 1
default 16:03:14.147528-0800    SpringBoard Observer is finished with bulletin 482D9DE2-E74C-4F73-B484-112F99DF1C62
default 16:03:14.147672-0800    SpringBoard List observer is finished with bulletin 482D9DE2-E74C-4F73-B484-112F99DF1C62
default 16:03:14.147742-0800    SpringBoard BBServer not purging bulletin <private> because still in use by an observer
default 16:03:14.147847-0800    PowerUIAgent    {"msg":"CLLocationManager", "event":"activity", "_cmd":"location", "self":"0x104c0c300"}
default 16:03:14.149107-0800    locationd   {"msg":"client getting effective client name", "bundleId":"", "bundlePath":"\/System\/Library\/LocationBundles\/SystemCustomization.bundle"}
default 16:03:14.152386-0800    locationd   {"msg":"#sbim client arrow state changed", "clientKey":"com.apple.locationd.bundle-\/System\/Library\/LocationBundles\/SystemCustomization.bundle", "entityClass":"SystemService", "oldArrowState":"Off", "newArrowState":"ReceivingLocationInformation", "dueToDeauthorization":0}
default 16:03:14.152604-0800    locationd   {"msg":"#sbim entity class arrow state changed", "entityClass":"SystemService", "oldArrowState":"RequestingLocationInformation", "newArrowState":"ReceivingLocationInformation", "dueToDeauthorization":0}
default 16:03:14.155081-0800    SpringBoard Posting notification id: 5787-BB3C; section: org.reactjs.native.example.FillRxApp; thread: C223-D62F; category: ; timestamp: 2020-11-25 00:03:13 +0000; actions: [ minimal: 0 (0 text), default: 0 (0 text) ]; destinations: [ {(
)} ]
default 16:03:14.155117-0800    SpringBoard Alerting on post for request 5787-BB3C. uiLocked=0 activeAlertDestinations=0 suppressAlertForContext=0 shouldSuppressForScreenTime=0
default 16:03:14.155157-0800    SpringBoard Sound can be played for notification 5787-BB3C: 0 [ hasRequest: 1 hasSound: 0 canPlaySound: 1 isInLostMode: 0 isDeviceUILocked: 0 alertsWhenLocked: 1 ]
default 16:03:14.155194-0800    SpringBoard Screen can be turned on for notification 5787-BB3C: 0 [ hasRequest: 1 canTurnOnDisplay: 1 caseIsEnabledAndLatched: 0 isInLostMode: 0 isDeviceUILocked: 0 alertsWhenLocked: 1 sentToLockScreenDestination: 0 sentToBannerDestination: 0 ]
default 16:03:14.155261-0800    SpringBoard Observer for NCBulletinNotificationSource: finished with bulletin 482D9DE2-E74C-4F73-B484-112F99DF1C62, transactionID 1
default 16:03:14.155328-0800    SpringBoard Observer is finished with bulletin 482D9DE2-E74C-4F73-B484-112F99DF1C62
default 16:03:14.155380-0800    SpringBoard List observer is finished with bulletin 482D9DE2-E74C-4F73-B484-112F99DF1C62
default 16:03:14.155430-0800    SpringBoard BBServer not purging bulletin <private> because still in use by an observer
default 16:03:14.158097-0800    PowerUIAgent    Found 3 long charges
default 16:03:14.158339-0800    PowerUIAgent    {"msg":"CLLocationManager", "event":"activity", "_cmd":"location", "self":"0x104c0c300"}
default 16:03:14.158731-0800    locationd   {"msg":"client getting effective client name", "bundleId":"", "bundlePath":"\/System\/Library\/LocationBundles\/SystemCustomization.bundle"}
default 16:03:14.159250-0800    PowerUIAgent    Current location Have Location, Location manager location: Have Location
default 16:03:14.166429-0800    PowerUIAgent    2 nearby LsOI
default 16:03:14.166610-0800    PowerUIAgent    Charged at LOI for 6 hours, present for 47 hours
default 16:03:14.166673-0800    PowerUIAgent    Charged at LOI for 14 hours, present for 65 hours
default 16:03:14.166709-0800    PowerUIAgent    Charged at LOI for 12 hours, present for 17 hours
default 16:03:14.166743-0800    PowerUIAgent    Not in typical charging location; Opting out of feature
default 16:03:14.166892-0800    PowerUIAgent    Monitor <private> suggested Fri Dec 29 15:47:32 0000
default 16:03:14.166946-0800    PowerUIAgent    Monitor <private> suggested Sun Dec 31 16:00:00 4000
default 16:03:14.166981-0800    PowerUIAgent    Monitors suggested: Fri Dec 29 15:47:32 0000
default 16:03:14.167970-0800    PowerUIAgent    Additional time from battery mitigation 0.0
default 16:03:14.169528-0800    PowerUIAgent    Deadline for full charge is: Fri Dec 29 15:47:32 0000 and resuming now would get us there by Tue Nov 24 16:32:09 2020
default 16:03:14.171246-0800    PowerUIAgent    Writing to PowerLog <private>
default 16:03:14.171701-0800    PowerUIAgent    Enabling charging (checkpoint=0)
default 16:03:14.172111-0800    PowerUIAgent    Status: <private>
default 16:03:14.172276-0800    PowerUIAgent    Checkpoint: 0
default 16:03:14.172420-0800    UserEventAgent  Registering job "<private>" due in 795 seconds.
default 16:03:14.176491-0800    dasd    Trigger: <private> is now [93]
default 16:03:14.495044-0800    DTServiceHub    Heartbeat
default 16:03:14.656764-0800    CommCenter  ari: (forwardIndication:123) Indication(0x25820000) for client(IndicationReregistrationActor) Type(GCD) size(110) dispq(AriHostIPC:0x10645ce20)
default 16:03:14.657226-0800    CommCenter  ind: Bin=[<private>]
default 16:03:14.990102-0800    DTServiceHub    Heartbeat
default 16:03:15.312628-0800    bluetoothd  Applying RSSI offset of 0 to -86, new rssi level is -86
default 16:03:15.494987-0800    DTServiceHub    Heartbeat
default 16:03:15.666215-0800    kernel  LQM-WiFi:TX(F8:1D:0F:62:61:08) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> BE<5 0 0 0 0 0 0 0 0 0 0> (5002ms)
default 16:03:15.666352-0800    kernel  LQM-WiFi:TX(F8:1D:0F:62:61:08) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> BK<0 0 0 0 0 0 0 0 0 0 0> (5002ms)
default 16:03:15.666445-0800    kernel  LQM-WiFi:TX(F8:1D:0F:62:61:08) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> VI<0 0 0 0 0 0 0 0 0 0 0> (5002ms)
default 16:03:15.666537-0800    kernel  LQM-WiFi:TX(F8:1D:0F:62:61:08) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> VO<0 0 0 0 0 0 0 0 0 0 0> (5002ms)
default 16:03:15.666625-0800    kernel  LQM-WiFi:L3 Control VO TX(F8:1D:0F:62:61:08) Success=0 NoACK=0 Expired=0 OtherErr=0
default 16:03:15.666697-0800    kernel  LQM-WiFi:TX(FF:FF:FF:FF:FF:FF) AC<SU MS NB NRS NA CM EX TF FFP MRET FLE> BE<0 0 0 0 0 0 0 0 0 0 0> (5002ms)
default 16:03:15.667015-0800    wifid   __WiFiDeviceProcessLqmTxStatsEvent: LQM-TX: Success:5(100.0%) Failure:0(0.0%) Retries:0(0.0%) NoACK:0(0.0%) Drops:0(0.0%) NoBuff:0(0.0%) NoRes:0(0.0%) ChipErr:0(0.0%) Expired:0(0.0%) ForcedExpiry:0(0.0%) Free:0(0.0%)
default 16:03:15.810477-0800    kernel  TRACER----> updateSlowWifiRxAmpduStats(13658)ChipStats: txba:0
default 16:03:15.821860-0800    kernel  LQM-WiFi:BT Coex Stats:btDur=26ms(0%) status=0x23 reqTypeMap=0x300000 req=38 gnt=21 abort=22616 rx1ovfl=0 latency=1098 sucPM=0 sucCTS2S=14 wlanTXPreempt=0 wlanRXPreempt=15 apTXafterPM=0 gntAudio=0 denyAudio=0 gntA2DP=0 denyA2DP=0 gntSniff=0 denySniff=0 [5522ms]
default 16:03:15.853738-0800    kernel  AppleCS42L77Audio::micBiasFastRampDown BiasCtrl:3
default 16:03:15.881998-0800    kernel  TRACER----> updateSlowWifiRxAmpduStats(13658)ChipStats: txba:0
default 16:03:15.974992-0800    kernel  LQM-WiFi: WeightAvgLQM rssi=-56 snr=34 txRate=65902 rxRate=126513
default 16:03:15.975106-0800    kernel  LQM-WIFI: Channel:11 chWidth:20 phyMode:16 nss:2 RSSI:-56 CCA:36 SNR:34 offChanDurUS:0 TVPMDurMS:0 concurrentIntDurMS:0 randomMac:1
default 16:03:15.975198-0800    kernel  LQM-WIFI: btAntDurMS:22 rc1CoexDurMS:0 rc2CoexDurMS:0 lteCoexDurMS:0 totalNonWLANDurMS:22 infraDutyCycle:100 lastScanType:0
default 16:03:15.975274-0800    kernel  LQM-WIFI: availWLANDurMS:5136 availTxDurMS:4853 realTxDurMS:6 availRxDurMS:5130 realRxDurMS:283 measurementDurMS:5158 lastScanDurMS:0
default 16:03:15.975351-0800    kernel  LQM-WIFI: Tx tput (i/p:0 o/p:0 expected:0)Mbps queueFullDurMS:0 avgLatencyMS:1 maxLatencyMS:1 phyRate(mode:65 avg:65 expected:0) phyRateTputRatio:0
default 16:03:15.975431-0800    kernel  LQM-WIFI: Tx AMPDUDensity(actual:1 expectedAtQueueFull:0) retries:0 fails:0 fwFrames:3 hostFrames:3 hostFails:0 ctlPkts:0(200) symptomsFails:0
default 16:03:15.975508-0800    kernel  LQM-WIFI: TxLim[1] outputBelowExpected:0 outputBelowInput:0 lowTxFrameCount:1 queueFull:0 highLatency:0 baselineNotAllowed:1 highSymptomsFails:0
default 16:03:15.975584-0800    kernel  LQM-WIFI: TxLim[1] lowPhyRate:0 lowPhyRateTputRatio:0 highPER:0 highRetries:0 lowTxAMPDUDensity:0 lowCCA:0 activeCoex:1 hostFWMismatch:0
default 16:03:15.975677-0800    kernel  LQM-WIFI: Rx tput:0 Mbps baseline:0 Mbps overflows:0 fcsFail:88 plcpBad:43 goodPlcps:750 crsGlitches:748 fwFrames:773 ucastFWFrames:7 hostFrames:3 AmpduDUP:0 APTxDataStallPct:0 rxAmpduTxBaMismatch:0
default 16:03:15.975766-0800    kernel  LQM-WIFI: Rx ucast(replays:0 decryptErrs:0) mcast(replays:0 decryptErrs:0) phyRate(mode:65 avg:96 expected:0) dups:0 retries:0 phyRateTputRatio:0
default 16:03:15.975853-0800    kernel  LQM-WIFI: RxLim[1] highRetries:0 highPhyPER:0 highDataPER:0 highOverflows:0 highRSSI:1 lowPhyRate:0 lowPhyRateTputRatio:0
default 16:03:15.975931-0800    kernel  LQM-WIFI: RxLim[1] highFCSErrors:0 highDups:0 highReplays:0 highDecryptErrors:0 highMCDecryptErrors:0 lowRxFrameCount:1
default 16:03:15.976011-0800    kernel  LQM-WIFI: UI Entry curState:Idle prevState:PendingIP event:ChannelQualityUpdate data:0
default 16:03:15.976083-0800    kernel  LQM-WIFI: UI Suboptimal link during idle
default 16:03:15.976135-0800    kernel  LQM-WIFI: UI Exit curState:Idle prevState:PendingIP
default 16:03:15.980947-0800    wifid   __WiFiDeviceManagerMonitor24GHzInfraNetworkTraffic: SNR 33.6, CCA 37.1, Tx bandwidth 48176.5 (kbps), Rx bandwidth 53529.2, Tx data rate 11.6 (kbps), Rx data rate  111.0, Tx air time 0.024 %, Rx air time 0.207 %, Good background traffic ? No
default 16:03:15.981093-0800    wifid   __WiFiDeviceManagerEvaluate24GHzInfraNetworkState:isConnected Yes, isTimeSensitiveAppRunning No, isThereTrafficNow No
default 16:03:15.990863-0800    DTServiceHub    Heartbeat
default 16:03:16.070624-0800    apsd    <private> updating AppLaunchStats with pending work <private>
default 16:03:16.070774-0800    apsd    <private> setting global pending work <private>
default 16:03:16.227827-0800    apsd    Releasing power assertion {identifier: APSCourier(tcpStream:dataReceived:)}
default 16:03:16.315269-0800    dasd    Attempting to suspend based on triggers: (     "com.apple.duetactivityscheduler.batterylevelpolicy.batterylevelchange" )
default 16:03:16.315422-0800    dasd    Ignoring trigger com.apple.duetactivityscheduler.batterylevelpolicy.batterylevelchange because conditions are deteriorating
default 16:03:16.315521-0800    dasd    Evaluating 0 activities based on triggers
default 16:03:16.330923-0800    locationd   MotionCoprocessor,startTime,627955396.398189,motionType,1,youthType,0,youthTypeReason,0
default 16:03:16.335930-0800    locationd   individual location data: type <private> location timestamp <private> pressure timestamp <private> location altitude <private> pressure altitude <private> location verticalUncertainty <private> horizontalUncertainty <private> lat <private> lon <private> current bias <private> track start at <private> end at <private> isPrefilteredLocation <private> fSlope <private> maxAbsSlope <private> fSpeed <private> fSpeedAccuracy <private> fEnvironment <private> fMatchQuality <private> altitude <private> verticalAccuracy <private> rawAltitude <private> rawVerticalAccuracy <private>
default 16:03:16.336061-0800    locationd   individual location data: type <private> location timestamp <private> pressure timestamp <private> location altitude <private> pressure altitude <private> location verticalUncertainty <private> horizontalUncertainty <private> lat <private> lon <private> current bias <private> track start at <private> end at <private> isPrefilteredLocation <private> fSlope <private> maxAbsSlope <private> fSpeed <private> fSpeedAccuracy <private> fEnvironment <private> fMatchQuality <private> altitude <private> verticalAccuracy <private> rawAltitude <private> rawVerticalAccuracy <private>
default 16:03:16.336182-0800    locationd   new centroid: latitude <private>, longitude <private>
default 16:03:16.336668-0800    locationd   cross entropy of type <private> is <private> calculated from baroAlt is <private> refAlt is <private> baroUncertainty is <private> refUncertainty is <private> track start at <private> end at <private>
default 16:03:16.336730-0800    locationd   cross entropy of type <private> is <private> calculated from baroAlt is <private> refAlt is <private> baroUncertainty is <private> refUncertainty is <private> track start at <private> end at <private>
default 16:03:16.336791-0800    locationd   pressure height rebase to type <private> new bias is <private> new bias uncertainty is <private> old baroAlt is <private> old refAlt is <private> old baroUncertainty is <private> old refUncertainty is <private> weatherEstimateInMeter is <private> calculated from track start at <private> end at <private>
default 16:03:16.337351-0800    locationd   Calibration track submitted with start time <private>, end time <private>
default 16:03:16.493007-0800    DTServiceHub    Heartbeat
default 16:03:16.994782-0800    DTServiceHub    Heartbeat
default 16:03:17.280298-0800    locationd   MotionCoprocessor,startTime,627955397.348630,motionType,4,youthType,0,youthTypeReason,0
default 16:03:17.284864-0800    locationd   os_transaction created: (<private>) <private>
default 16:03:17.285249-0800    locationd   @WifiLogic, handleInput, System::CoarseMotion
default 16:03:17.289916-0800    locationd   {"msg":"CLWifi1SystemLogic::apply", "event":"elapsed", "begin_mach":7096171889435, "end_mach":7096172002707, "elapsed_s":"0.004719667", "event":"System::CoarseMotion", "now_s":"627955397.284263968"}
default 16:03:17.292320-0800    locationd   os_transaction releasing: (<private>) <private>
default 16:03:17.295784-0800    sharingd    Stationary: yes -> no
default 16:03:17.295895-0800    aggregated  Register notification block
default 16:03:17.296962-0800    aggregated  Register notification block
default 16:03:17.297630-0800    aggregated  Register notification block
default 16:03:17.298784-0800    aggregated  Register notification block
default 16:03:17.299115-0800    aggregated  Register notification block
default 16:03:17.299242-0800    aggregated  Register notification block
default 16:03:17.300488-0800    aggregated  Register notification block
default 16:03:17.301915-0800    aggregated  Register notification block
default 16:03:17.304864-0800    aggregated  Register notification block
default 16:03:17.305609-0800    aggregated  Register notification block
default 16:03:17.306571-0800    aggregated  Register notification block
default 16:03:17.307683-0800    aggregated  Register notification block
default 16:03:17.494630-0800    DTServiceHub    Heartbeat
default 16:03:17.598051-0800    locationd   MotionCoprocessor,startTime,627955397.666757,motionType,2,youthType,0,youthTypeReason,0
default 16:03:17.602734-0800    locationd   os_transaction created: (<private>) <private>
default 16:03:17.603910-0800    locationd   @WifiLogic, handleInput, System::CoarseMotion
default 16:03:17.606669-0800    locationd   {"msg":"CLWifi1SystemLogic::apply", "event":"elapsed", "begin_mach":7096179522401, "end_mach":7096179585176, "elapsed_s":"0.002615625", "event":"System::CoarseMotion", "now_s":"627955397.602350950"}
default 16:03:17.606890-0800    locationd   os_transaction releasing: (<private>) <private>
default 16:03:17.609807-0800    sharingd    NearbyInfo: Starting scan: blob <>/<>, devices 1, rate Normal, RSSI -60, dups no, cache no, tracked 0, force yes, stop yes
default 16:03:17.610714-0800    sharingd    Nearby stop scanning: scan request of type 16, blob: {length = 0, bytes = 0x}, mask {length = 0, bytes = 0x}, active: 0, duplicates: 0, screen on: No Scan, screen off: No Scan, locked: 1,  rssi: -90, peers: (
) nearby scan mode: 10, adv buf: 0, advbuf mode: 4, priority critical: 0, range: 0
default 16:03:17.610789-0800    sharingd    Nearby start scanning with data: scan request of type 16, blob: {length = 0, bytes = 0x}, mask {length = 0, bytes = 0x}, active: 0, duplicates: 0, screen on: 300, screen off: 300, locked: 1,  rssi: -60, peers: (
    "197F1CDC-8B1B-604A-1414-F3468AF9FA1B"
) nearby scan mode: 10, adv buf: 0, advbuf mode: 4, priority critical: 0, range: 0
default 16:03:17.611905-0800    bluetoothd  Stop scanning for process sharingd (63) with scan request of type 16, blob: {length = 0, bytes = 0x}, mask {length = 0, bytes = 0x}, active: 0, duplicates: 0, screen on: No Scan, screen off: No Scan, locked: 1,  rssi: -90, peers: (
) nearby scan mode: 10, adv buf: 0, advbuf mode: 4, priority critical: 0, range: 0
default 16:03:17.611989-0800    bluetoothd  Removing scan request scan request of type 16, blob: {length = 0, bytes = 0x}, mask {length = 0, bytes = 0x}, active: 0, duplicates: 0, screen on: No Scan, screen off: No Scan, locked: 1,  rssi: -90, peers: (
) nearby scan mode: 10, adv buf: 0, advbuf mode: 4, priority critical: 0, range: 0 for client 275C1220-B899-4AD6-8F27-296BA993C428
default 16:03:17.612230-0800    bluetoothd  Passively scanning for devices of types: 4 5 7 9 12 15 18 (Window: 30/Interval: 300)
default 16:03:17.612312-0800    bluetoothd  About to scan for type: 7 - rssi: -60 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.612371-0800    bluetoothd  About to scan for type: 15 - rssi: -70 - range: 1 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.612421-0800    bluetoothd  About to scan for type: 9 - rssi: -90 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.612471-0800    bluetoothd  About to scan for type: 5 - rssi: -80 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.612557-0800    bluetoothd  About to scan for type: 4 - rssi: -40 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0xff000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.612679-0800    bluetoothd  About to scan for type: 12 - rssi: -90 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 1
default 16:03:17.612781-0800    bluetoothd  About to scan for type: 18 - rssi: -100 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.613809-0800    bluetoothd  Scan options changed: 1
default 16:03:17.614285-0800    bluetoothd  Received XPC message "CBMsgIdStopScan" from session "com.apple.bluetoothd-central-3719-28"
default 16:03:17.614986-0800    bluetoothd  Start scanning for process sharingd (63) with scan request of type 16, blob: {length = 0, bytes = 0x}, mask {length = 0, bytes = 0x}, active: 0, duplicates: 0, screen on: 300, screen off: 300, locked: 1,  rssi: -60, peers: (
    "197F1CDC-8B1B-604A-1414-F3468AF9FA1B"
) nearby scan mode: 10, adv buf: 0, advbuf mode: 4, priority critical: 0, range: 0
default 16:03:17.615108-0800    bluetoothd  Adding scan request called
default 16:03:17.615277-0800    bluetoothd  Adding scan request scan request of type 16, blob: {length = 22, bytes = 0x00000000000000000000000000000000000000000000}, mask {length = 22, bytes = 0x00000000000000000000000000000000000000000000}, active: 0, duplicates: 0, screen on: 300, screen off: 300, locked: 1,  rssi: -60, peers: (
    "197F1CDC-8B1B-604A-1414-F3468AF9FA1B"
) nearby scan mode: 10, adv buf: 0, advbuf mode: 4, priority critical: 0, range: 0 for client 275C1220-B899-4AD6-8F27-296BA993C428
default 16:03:17.615519-0800    bluetoothd  Passively scanning for devices of types: 4 5 7 9 12 15 16 18 (Window: 30/Interval: 300)
default 16:03:17.615570-0800    bluetoothd  About to scan for type: 7 - rssi: -60 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.615618-0800    bluetoothd  About to scan for type: 16 - rssi: -60 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 1
default 16:03:17.615669-0800    bluetoothd  About to scan for type: 15 - rssi: -70 - range: 1 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.615716-0800    bluetoothd  About to scan for type: 9 - rssi: -90 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.615771-0800    bluetoothd  About to scan for type: 5 - rssi: -80 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.615819-0800    bluetoothd  About to scan for type: 4 - rssi: -40 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0xff000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.615869-0800    bluetoothd  About to scan for type: 12 - rssi: -90 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 1
default 16:03:17.615920-0800    bluetoothd  About to scan for type: 18 - rssi: -100 - range: 0 - payload: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - mask: {length = 22, bytes = 0x00000000000000000000000000000000000000000000} - peers: 0
default 16:03:17.616776-0800    bluetoothd  Scan options changed: 1
default 16:03:17.625607-0800    bluetoothd  Received 'stop scan' request from session "com.apple.bluetoothd-central-3719-28"
mikehardy commented 3 years ago

This still seems to come from console.app. It's got all sorts of things mixed in. Is this from xcode after launch from xcode?

jeremycod commented 3 years ago

Hi @mikehardy

I'm not very familiar with xcode, so maybe I don't understand quite well which console output you are looking for. The one that I've sent you is from Window -> Devices and simulator -> my phone -> Open Console

There is also another console output available from View -> Debug Area -> Activate Console, but this one doesn't display any logs related to the device. It only displays [javascript] logs from the app, and when this problem happens there is no output in this console.

If there is some third console that I'm not aware of can you please tell me how to activate it? I'm running app as release as you previously advised.

mikehardy commented 3 years ago

Hmm - for me it is when I say Activate Console, but I get more than javascript in that one, I get the firebase-ios-sdk messages as well on boot up etc. But without all the operating-system-level noise. You can verify this by throwing some native log statements into the ios code that handles messaging initialization on app startup to see that the Xcode debug console area should be printing native things as well. That said, nothing at all stands out to me in the log above except it seems like one cloud message with notification content was delivered

jeremycod commented 3 years ago

I'm getting there some firebase output at the beginning, but it's just a few lines:

2020-11-24 18:08:51.252373-0800 FillRxApp[8567:2781105] 7.1.0 - [Firebase/Core][I-COR000003] The default Firebase app has not yet been configured. Add `[FIRApp configure];` (`FirebaseApp.configure()` in Swift) to your application initialization. Read more: https://goo.gl/ctyzm8.
2020-11-24 18:08:51.266882-0800 FillRxApp[8567:2781111] 7.1.0 - [Firebase/Analytics][I-ACS023007] Analytics v.7.1.0 started
2020-11-24 18:08:51.266921-0800 FillRxApp[8567:2781111] 7.1.0 - [Firebase/Analytics][I-ACS023008] To enable debug logging set the following application argument: -FIRAnalyticsDebugEnabled (see http://goo.gl/RfcP7r)
2020-11-24 18:08:51.268996-0800 FillRxApp[8567:2781112] 7.1.0 - [Firebase/Messaging][I-FCM001000] FIRMessaging Remote Notifications proxy enabled, will swizzle remote notification receiver handlers. If you'd prefer to manually integrate Firebase Messaging, add "FirebaseAppDelegateProxyEnabled" to your Info.plist, and set it to NO. Follow the instructions at:
https://firebase.google.com/docs/cloud-messaging/ios/client#method_swizzling_in_firebase_messaging
to ensure proper integration.
2020-11-24 18:08:51.271679-0800 FillRxApp[8567:2781092] [native] Running application FillRxApp ({
    initialProps =     {
        isHeadless = 0;
    };
    rootTag = 1;
})
2020-11-24 18:08:51.301399-0800 FillRxApp[8567:2781105] 7.1.0 - [Firebase/Analytics][I-ACS800023] No pending snapshot to activate. SDK name: app_measurement
2020-11-24 18:08:51.323511-0800 FillRxApp[8567:2781111] 7.1.0 - [Firebase/Analytics][I-ACS023012] Analytics collection enabled
2020-11-24 18:08:51.323552-0800 FillRxApp[8567:2781111] 7.1.0 - [Firebase/Analytics][I-ACS023220] Analytics screen reporting is enabled. Call +[FIRAnalytics logEventWithName:FIREventScreenView parameters:] to log a screen view event. To disable automatic screen reporting, set the flag FirebaseAutomaticScreenReportingEnabled to NO (boolean) in the Info.plist

and just few of these:

2020-11-24 18:08:51.628100-0800 FillRxApp[8567:2781092] [native] [GESTURE HANDLER] Initialize gesture handler for root view <RCTRootContentView: 0x101b0dda0; reactTag: 1; frame = (0 0; 414 896); gestureRecognizers = <NSArray: 0x2829706f0>; layer = <CALayer: 0x282778540>>

2020-11-24 18:09:22.056141-0800 FillRxApp[8567:2781092] [Snapshotting] Snapshotting a view (0x105114a30, _UIReplicantView) that has not been rendered at least once requires afterScreenUpdates:YES.

Everything else are javascript messages from my code and when I send notification that is not received on the other end I don't have anything added to this console.

jeremycod commented 3 years ago

I've added -FIRAnalyticsDebugEnabled and -FIRMessagesDebugEnabled argument to XCode schema and now I'm getting this log each time new message arrives

2020-11-24 20:44:45.881383-0800 FillRxApp[8586:2818378] 7.1.0 - [Firebase/Messaging][I-FCM016004] Added sync message to cache: 1606279485661442
mikehardy commented 3 years ago

I was looking for the -FIRMessagesDebugEnabled flag as I wanted to recommend it but couldn't find the exact thing, glad you found it. You're doing everything I would expect, and as you say it seems to work on other devices yes? Why it is not working on this one, I simply can't say, I am sorry. If you are absolutely sure you are on firebase-ios-sdk 7.1.0 (you can set it in your Podfile as an override https://rnfirebase.io/#ios) and it's still not working then all I can recommend is seeing if you can repro with a native / pure / not-react-native quickstart and pursuing upstream. https://github.com/firebase/quickstart-android/tree/master/messaging

jeremycod commented 3 years ago

Overriding firebase sdk makes it completely stop working. Nothing is going on when I do that. I'm not sure why. Both with and without manual override 'pod install' installs 7.1.0 version (see bellow), but without override I'm able to receive first few messages before it stops and I still see that "Added sync message to cache" after it's blocked, but with sdk override nothing is going on from the beginning.

Installing Firebase (7.1.0)
Installing FirebaseAnalytics (7.1.0)
Installing FirebaseAuth (7.1.0)
Installing FirebaseCore (7.1.0)
Installing FirebaseCoreDiagnostics (7.1.0)
Installing FirebaseInstallations (7.1.0)
Installing FirebaseInstanceID (7.1.0)
Installing FirebaseMessaging (7.1.0)

Does it indicate some potential problem?

mikehardy commented 3 years ago

There's no reason v7.1.0 should stop things completely. That's unexpected.

jeremycod commented 3 years ago

I've tried again, and this time it has the same behaviour like earlier. It stops after 4-5 messages.

marceloamoretti commented 3 years ago

I have the same issue here. By trying to send a notification through node, I got the following error: 'The provided registration token is not registered. A previously valid registration token can be unregistered for a variety of reasons. See the error documentation for more details. Remove this registration token and stop using it to send messages.' It happens only on iOS after I receive exactly 2 notifications.

jeremycod commented 3 years ago

I'm not sure if these two are the same issues. I've also have seen the problem you are explaining when receiver update token to the backend and write away backend receive message that token is unregistered. I didn't explore this problem too much as I thought it might be related to the frequent redeployment of the app during development. In my case, FCM is successfully submitted from the backend and it's received on the device, but it doesn't trigger onMessage.

bgraf-zlab commented 3 years ago

Hey, I just stumbled over this issue by accident and I hope this is not unneccesary noise to you, but I wanted to mention that iOS sometimes limits delivering push notifications to an app. This happens to us with "silent" notifications that we want to process while the app is running in the foreground. The actual limit is not documented, but Apple recommends to not send more than 2-3 notifications per hour. My experience is that the limit is about 3-4 notifications within 5 minutes or so. Beyond that limit, the phone will still receive notifications afterwards, but iOS won't deliver them to the app anymore. Maybe you're running into the same problem. Best, Benjamin.

jeremycod commented 3 years ago

Hi @bgraf-zlab ,

Thanks for this information. This make sense to some extent. 1) This happens while I'm testing push notifications, so I'm sending it one after the other until it stops coming, which is after 3-5 successful notifications. 2) After it stops coming if I leave device, wait 5 - 10 minutes, and start sending again, usually it comes again and stops again. So, everything above is in favour of what you explained.

On the other hand, there are few other things which don't seem to match:

3) I'm testing on 2 additional iPhone devices as well and I was never able to reproduce the same issue there. It's always on one particular device. Unless Apple has blacklisted that specific device only, that doesn't fit. 4) When this issue happens, I can still see some log in XCode console. I'm not sure what this log means, but it looks like message came to the device, but it's blocked somewhere on the device:

2020-11-24 20:44:45.881383-0800 FillRxApp[8586:2818378] 7.1.0 - [Firebase/Messaging][I-FCM016004] Added sync message to cache: 1606279485661442
mikehardy commented 3 years ago

ios reserves the right to thermally throttle or power throttle any activity like this, could be something like that I remember in the big bugfix rodeo for messaging here #3339 part of the difficulty in testing it was that the physical device they/we were using was old and thermally throttled :weary: - resulted in behavior like this on one device only

jeremycod commented 3 years ago

Hi @mikehardy

This sounds interesting and worth of some investigation. Is it possible to somehow confirm if it's one of these cases?

Just for the record. This device is 1 month old iPhone 11.

Also, can you confirm if I would still see this log when device is throttled by Apple?

2020-11-24 20:44:45.881383-0800 FillRxApp[8586:2818378] 7.1.0 - [Firebase/Messaging][I-FCM016004] Added sync message to cache: 1606279485661442
mikehardy commented 3 years ago

Unfortunately I don't have further info on it - it's in the "vague memory but from trusted source" department, as opposed to direct experience

Salakar commented 3 years ago

This is indeed the device throttling the message, you can see the device receives it but ios cancels delivery of the message to the application;

CANCELED: com.apple.pushLaunch.org.reactjs.native.example.FillRxApp:C40557 at priority 10 <private>!
Salakar commented 3 years ago

To add, sometimes the logs tells you why it's cancelled, e.g. Low battery, High CPU Usage policy, Thundering Heard policy etc and other times like this it doesn't tell you at all

Our general recommendation is that you don't rely on data/silent messages for anything critical (I think we explicitly added this to the FlutterFire docs but not been added to RNFB yet).

An example scenario of something non-critical would be to notify your app that a new piece of content is available so your app can download/cache it ahead of time for quicker loads when the user next opens the app. However should the silent message not go through; the app still functions and just loads content without local cache, albeit slower.

jeremycod commented 3 years ago

Hi @Salakar

Thanks a lot for this information. I'm breaking my head for 2 weeks over this and trying to figure out what I'm doing wrong here and why FCM notifications behaves in different way on different devices.

This is indeed the device throttling the message, you can see the device receives it but ios cancels delivery of the message to the application;

To add, sometimes the logs tells you why it's cancelled, e.g. Low battery, High CPU Usage policy, Thundering Heard policy etc and other times like this it doesn't tell you at all

Did I correctly understand this that if message is throttled by device there is nothing I can do in the app level to fix it or improve it? It's simply out of scope and it might happen on other devices.

Our general recommendation is that you don't rely on data/silent messages for anything critical (I think we explicitly added this to the FlutterFire docs but not been added to RNFB yet).

An example scenario of something non-critical would be to notify your app that a new piece of content is available so your app can download/cache it ahead of time for quicker loads when the user next opens the app. However should the silent message not go through; the app still functions and just loads content without local cache, albeit slower.

Completely agree with this. That's exactly how I'm using it. App will update the content on user action if FCM fails to notify it about content change. I would just like to remove all potential mistakes on my side, and also to understand all potential causes of these kind of problems so I can advice users if there is a need for that.

cozmoc commented 3 years ago

'The provided registration token is not registered. A previously valid registration token can be unregistered for a variety of reasons. See the error documentation for more details. Remove this registration token and stop using it to send messages.'

I am still facing the same issue since 3 months. did you manage to find a fix?

bgraf-zlab commented 3 years ago

Hey @jeremycod,

1. I'm testing on 2 additional iPhone devices as well and I was never able to reproduce the same issue there. It's always on one particular device.  Unless Apple has blacklisted that specific device only, that doesn't fit.

I did also observe different behaviour on different devices. This throttling algorhythm really is a blackbox, which makes testing a bit annoying. However I also see those CANCELLED messages in the log showing up; I guess as long as they show up, the implementation itself is fine and the rest is not in our hands.

(Btw. I also had a phone do no throttling at all once – it was fully charged and connected to a charger, so maybe that helps for debugging and testing, too.)

cozmoc commented 3 years ago

finally found the solution! I was using messaging().deleteToken() for logout but apparently the library does not refresh the token if that is used again. so this fixed my issue finally:

messaging().deleteToken(undefined, '*'); and messaging().getToken(undefined, '*').then(......

stale[bot] commented 3 years ago

Hello 👋, to help manage issues we automatically close stale issues. This issue has been automatically marked as stale because it has not had activity for quite some time. Has this issue been fixed, or does it still require the community's attention?

This issue will be closed in 15 days if no further activity occurs. Thank you for your contributions.

mikehardy commented 3 years ago

This thread is very useful for identifying:

1) the debug flags that can help analyze the ios delivery problem: https://github.com/invertase/react-native-firebase/issues/4603#issuecomment-733462018 2) the debug log messages that help identify that throttling is the problem: https://github.com/invertase/react-native-firebase/issues/4603#issuecomment-738335936

nabeelpkl commented 3 years ago

any solution for this?