Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Issue goes on with Cloud Messaging Push Notification to iOS device (in 5.17.0) #2438

Closed
Sunrise17 opened this issue Feb 24, 2019 · 72 comments
Closed
Assignees
Milestone

Comments

@Sunrise17
Copy link

Sunrise17 commented Feb 24, 2019

### Environment

  • Xcode version: 10.1
  • Deployment Target: 12.1
  • Firebase SDK version: 5.17.0 (Updated from 5.16.0)
  • Firebase Component: Core, Messaging
  • Component version: * Core 5.17.0, Messaging 3.3.1
    CocoaPods 1.6.0
    Using Bolts (1.9.0)
    Using BoringSSL-GRPC (0.0.2)
    Using FBSDKCoreKit (4.40.0)
    Using FBSDKLoginKit (4.40.0)
    Using Firebase (5.17.0)
    Using FirebaseAnalytics (5.6.0)
    Using FirebaseAnalyticsInterop (1.2.0)
    Using FirebaseAuth (5.3.1)
    Using FirebaseAuthInterop (1.0.0)
    Using FirebaseCore (5.3.0)
    Using FirebaseDatabase (5.1.0)
    Using FirebaseFirestore (1.0.1)
    Using FirebaseInstanceID (3.5.0)
    Using FirebaseMessaging (3.3.1)
    Using GTMSessionFetcher (1.2.1)
    Using Google-Mobile-Ads-SDK (7.40.0)
    Using GoogleAppMeasurement (5.6.0)
    Using GoogleUtilities (5.3.7)
    Using Protobuf (3.6.1)
    Using gRPC-C++ (0.0.6)
    Using gRPC-Core (1.17.0)
    Using leveldb-library (1.20)
    Using nanopb (0.3.901)

### Problem

I have problem when using FCM in iOS. When i run the code from XCode for the first time and fresh install app to the device, app starts receiving notification from Cloud Messaging Console and from my Python server without an issue. After i stop the code and run the app from the device, It stopped receiving any notification with following error below; If i delete the app and again re-install from Xcode, it starts receiving notification with new fcmToken, till i restart the app.

Received Error from Python Server;

{
  "error": {
    "code": 404,
    "message": "Requested entity was not found.",
    "status": "NOT_FOUND",
    "details": [
      {
        "@type": "type.googleapis.com/google.firebase.fcm.v1.FcmError",
        "errorCode": "UNREGISTERED"
      }
    ]
  }
}

Relevant Code:

Code in App AppDelegate.swift

import UIKit
import Firebase
import UserNotifications

@UIApplicationMain
class AppDelegate: UIResponder, UIApplicationDelegate {
    
    var window: UIWindow?
    
    func application(_ application: UIApplication, didFinishLaunchingWithOptions launchOptions: [UIApplication.LaunchOptionsKey : Any]? = nil) -> Bool {
        
        //Firebase Setup
        FirebaseApp.configure()
        
        Messaging.messaging().delegate = self
        
        UNUserNotificationCenter.current().delegate = self
        let authOptions: UNAuthorizationOptions = [.alert, .badge, .sound]
        UNUserNotificationCenter.current().requestAuthorization( options: authOptions, completionHandler: {_, _ in } )
        application.registerForRemoteNotifications()
        
        return true
    }
    
    func applicationWillResignActive(_ application: UIApplication) {
    }
    
    func applicationDidEnterBackground(_ application: UIApplication) {
    }
    
    func applicationWillEnterForeground(_ application: UIApplication) {
    }
    
    func applicationWillTerminate(_ application: UIApplication) {
    }
    
    func applicationDidBecomeActive(_ application: UIApplication) {
        //Reset Bagde while entering App
        if (UIApplication.shared.applicationIconBadgeNumber != 0) {
            UIApplication.shared.applicationIconBadgeNumber = 0
        }
    }
    
    func application(_ application: UIApplication, didRegisterForRemoteNotificationsWithDeviceToken deviceToken: Data) {
        print("APNs token retrieved: \(deviceToken.hexString)")
    }
    
    func application(_ application: UIApplication, didFailToRegisterForRemoteNotificationsWithError error: Error) {
        print("Unable to register for remote notifications: \(error.localizedDescription)")
    }   
}

extension AppDelegate: UNUserNotificationCenterDelegate {

    func userNotificationCenter(_ center: UNUserNotificationCenter, willPresent notification: UNNotification, withCompletionHandler completionHandler: @escaping (UNNotificationPresentationOptions) -> Void) {
        
        let userInfo = notification.request.content.userInfo
        print("userInfo \(userInfo)")
        
        completionHandler([.alert, .badge, .sound])
    }
    
    func userNotificationCenter(_ center: UNUserNotificationCenter, didReceive response: UNNotificationResponse, withCompletionHandler completionHandler: @escaping () -> Void) {
        
        let userInfo = response.notification.request.content.userInfo
        print("userInfo \(userInfo)")
    
        completionHandler()
    }
    
}

extension AppDelegate: MessagingDelegate {
    
    func messaging(_ messaging: Messaging, didReceiveRegistrationToken fcmToken: String) {
        print("Firebase registration token: \(fcmToken)")
    }
    
    func messaging(_ messaging: Messaging, didReceive remoteMessage: MessagingRemoteMessage) {
        print("Received data message: \(remoteMessage.appData)")
    }
}

extension Data {
    public var hexString: String {
        var string = ""
        enumerateBytes { (buffer, _, _) in
            buffer.forEach({ (byte) in
                string = string.appendingFormat("%02x", byte)
            })
        }
        return string
    }
}
@xiao99xiao
Copy link

xiao99xiao commented Feb 27, 2019

I met exactly the same issue.

Using curl and fcmToken to send push to devices that could not receive notifications, I got this similar with @Sunrise17 :

{
  "multicast_id": 6325237028895013844,
  "success": 0,
  "failure": 1,
  "canonical_ids": 0,
  "results": [
    {
      "error": "NotRegistered"
    }
  ]
}

Update: I made more tests and summary goes below.

  1. Pod update/install. Do a clean install on device.
  2. Request for notification permission. Received a fcm token A. The token A is valid, can be used to send notification.
  3. Restart the app, received a new fcm token B, use B to send notification, got error 'NotRegistered'
  4. Repeat step 3 for 4-6 times, received another new fcm token every time, all 'NotRegistered'
  5. After repeating so many times, there is a chance to receive a new fcm token that works, since then, restarting the app will not refresh the fcm token any more. Issue disappears.
@zohaib-ehsan
Copy link

Any update on this? I also tried 5.17. But after the first install, subsequent tokens are not valid. I am also receiving "NotRegistered" error.

@DragoX
Copy link

DragoX commented Mar 4, 2019

I believe I have exactly the same issue - you launch app once after installation - push notifications work fine. But as soon as you close the app and launch it again - push-notifications are not being delivered with the following server response:

{
    "multicast_id": xxxxx,
    "success": 0,
    "failure": 1,
    "canonical_ids": 0,
    "results": [
        {
            "error": "NotRegistered"
        }
    ]
}

So I've looked into the Firebase detail logs in the app and that what I've found:

  1. First launch of the app:
2019-03-04 15:09:52.694096-0800 app[24321:1707255] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:09:52.695714-0800 app[24321:1707255] 5.17.0 - [Firebase/InstanceID][I-IID007006] Checkin parameters: {
2019-03-04 15:09:53.128416-0800 app[24321:1707258] 5.17.0 - [Firebase/InstanceID][I-IID007002] Invalid last checkin timestamp in future.
2019-03-04 15:09:53.128864-0800 app[24321:1707258] 5.17.0 - [Firebase/InstanceID][I-IID007003] Checkin successful with authId: 5487083580506054298, digest: OHxjuBRzCVLDGaWiWerLnw==, lastCheckinTimestamp: 1551740992000
2019-03-04 15:09:53.129216-0800 app[24321:1707258] 5.17.0 - [Firebase/InstanceID][I-IID005004] Successfully got checkin credentials
ioApp[24321:1707258] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:09:53.136110-0800 app[24321:1707258] 5.17.0 - [Firebase/InstanceID][I-IID005002] Checkin success.
2019-03-04 15:09:54.461605-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID013002] Removed cached checkin preferences from Keychain.
2019-03-04 15:09:54.461881-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID013006] App reset detected. Will delete server registrations.
2019-03-04 15:09:54.462513-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID021000] Unregister request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5251351696422095184&plat=2&app=app.ios&app_ver=1.1.13_dev_100&X-cliv=fiid-3.3.1&delete=true
2019-03-04 15:09:54.463073-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID003012] Provisioning profile has specifically provisioned devices, most likely a Dev profile.
2019-03-04 15:09:54.463264-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID003013] APNS Environment in profile: development
2019-03-04 15:09:54.463376-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:09:54.463834-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:09:54.464261-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:09:54.464656-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:09:54.465197-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:09:54.465600-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID014007] Successfully delet2019-03-04 15:09:54.465742-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID014000] Fetch new token for authorizedEntity: 344034181945, scope: *
2019-03-04 15:09:54.465879-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID014000] Fetch new token for authorizedEntity: 344034181945, scope: *
2019-03-04 15:09:54.469716-0800 app[24321:1707283] 5.17.0 - [Firebase/InstanceID][I-IID020000] Register request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5487083580506054298&X-scope=*&plat=2&app=app.ios&app_ver=1.1.13_dev_100&X-cliv=fiid-3.3.1&sender=344034181945&X-subtype=344034181945&appid=eMOR5zgHp14&gmp_app_id=1:344034181945:ios:bd757d1e5b1e6e49
2019-03-04 15:09:54.691811-0800 app[24321:1707255] 5.17.0 - [Firebase/InstanceID][I-IID020000] Register request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5487083580506054298&X-scope=*&plat=2&app=app.ios&app_ver=1.1.13_dev_100&X-cliv=fiid-3.3.1&sender=344034181945&X-subtype=344034181945&appid=eMOR5zgHp14&gmp_app_id=1:344034181945:ios:bd757d1e5b1e6e49
2019-03-04 15:09:54.691956-0800 app[24321:1707255] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't deleFirebase/InstanceID][I-IID014001] Token fetch successful, token: [TOKEN_1], authorizedEntity: 344034181945, scope:*
2019-03-04 15:09:54.762234-0800 app[24321:1707258] 5.17.0 - [Firebase/InstanceID][I-IID014001] Token fetch successful, token: [TOKEN_1], authorizedEntity: 344034181945, scope:*
2019-03-04 15:09:54.762862-0800 app[24321:1707258] 5.17.0 - [Firebase/InstanceID][I-IID003016] Received APNS token while fetching default token. Refetching default token.
2019-03-04 15:09:54.763037-0800 app[24321:1707258] 5.17.0 - [Firebase/InstanceID][I-IID014000] Fetch new token for authorizedEntity: 344034181945, scope: *
2019-03-04 15:09:54.763282-0800 app[24321:1707258] 5.17.0 - [Firebase/InstanceID][I-IID020000] Register request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5487083580506054298&X-scope=*&plat=2&app=app.ios&app_v2019-03-04 15:09:54.930314-0800 app[24321:1707258] 5.17.0 - [Firebase/InstanceID][I-IID014001] Token fetch successful, token: [TOKEN_1], authorizedEntity: 344034181945, scope:*
2019-03-04 15:09:54.930398-0800 app[24321:1707258] 5.17.0 - [Firebase/InstanceID][I-IID003010] Successfully fetched default token.
 5.17.0 - [Firebase/InstanceID][I-IID003008] Got default token [TOKEN_1]

Firebase token obtained and can be successfully used for sending messages.

  1. Seconds (and following) launches:
2019-03-04 15:11:18.443544-0800 app[24329:1707877] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:11:18.450881-0800 app[24329:1707882] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:11:18.452160-0800 app[24329:1707882] 5.17.0 - [Firebase/InstanceID][I-IID009000] No keypair info is retrieved with tag com.google.iid-|K|
2019-03-04 15:11:18.466275-0800 app[24329:1707882] 5.17.0 - [Firebase/InstanceID][I-IID007006] Checkin parameters: {
2019-03-04 15:11:18.805291-0800 app[24329:1707910] 5.17.0 - [Firebase/InstanceID][I-IID007002] Invalid last checkin timestamp in future.
2019-03-04 15:11:18.805542-0800 app[24329:1707910] 5.17.0 - [Firebase/InstanceID][I-IID007003] Checkin successful with authId: 5643432206176300780, digest: X5OaCKm9T9wvjC/uSd/YVQ==, lastCheckinTimestamp: 1551741078000
2019-03-04 15:11:18.806601-0800 app[24329:1707910] 5.17.0 - [Firebase/InstanceID][I-IID005004] Successfully got chec2019-03-04 15:11:18.806775-0800 app[24329:1707910] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:11:18.807475-0800 app[24329:1707910] 5.17.0 - [Firebase/InstanceID][I-IID005002] Checkin success.
2019-03-04 15:11:19.327644-0800 app[24329:1707882] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:11:19.328725-0800 app[24329:1707882] 5.17.0 - [Firebase/InstanceID][I-IID013002] Removed cached checkin preferences from Keychain.
2019-03-04 15:11:19.692745-0800 app[24329:1707882] 5.17.0 - [Firebase/InstanceID][I-IID013006] App reset detected. Will delete server registrations.
2019-03-04 15:11:19.692858-0800 app[24329:1707882] 5.17.0 - [Firebase/InstanceID][I-IID021000] Unregister request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5487083580506054298&plat=2&app=app.ios&app_ver=1.1.13_dev_100&X-cliv=fiid-3.3.1&delete=true
2019-03-04 15:11:19.694558-0800 app[24329:1707882] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:11:19.695667-0800 app[24329:1707882] 5.17.0 - [Firebase/InstanceID][I-IID009000] No keypair info is retrieved with tag com.google.iid.keypair.private-app.ios
2019-03-04 15:11:19.695870-0800 app[24329:1707882] 5.17.0 - [Firebase/InstanceID][I-IID003012] Provisioning profile has specifically provisioned devices, most likely a Dev profile.
2019-03-04 15:11:19.696070-0800 app[24329:1707882] 5.17.0 - [Firebase/InstanceID][I-IID003013] APNS Environment in profile: development
2019-03-04 15:11:19.770448-0800 app[24329:1707903] 5.17.0 - [Firebase/InstanceID][I-IID014007] Successfully deleted GCM server registrations on app reset

Firebase is cleaning up GCM server registrations because it detects application reset by some reason:
App reset detected. Will delete server registrations
And not re-generating and providing refreshed token in callbacks anymore.

So I've ended up adding this workaround:

        let deleteCount = UserDefaults.standard.integer(forKey: oneTimeWorkaroundKey)
        if deleteCount == 0 {
            InstanceID.instanceID().deleteID { error in
                if let cError = error {
                    log("APNS: Error on delete: \(cError)")
                } else {
                    UserDefaults.standard.set(deleteCount + 1, forKey: oneTimeWorkaroundKey)
                }
            }
        }

Executing this code after app launch yeilds these log records:

2019-03-04 15:14:50.988141-0800 app[24344:1709337] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:14:50.988938-0800 app[24344:1709337] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:14:50.989024-0800 app[24344:1709337] 5.17.0 - [Firebase/InstanceID][I-IID009000] No keypair info is retrieved with tag com.google.iid-|K|
2019-03-04 15:14:51.027302-0800 app[24344:1709337] 5.17.0 - [Firebase/InstanceID][I-IID007006] Checkin parameters: {
2019-03-04 15:14:51.353852-0800 app[24344:1709377] 5.17.0 - [Firebase/InstanceID][I-IID007002] Invalid last checkin timestamp in future.
2019-03-04 15:14:51.353889-0800 app[24344:1709377] 5.17.0 - [Firebase/InstanceID][I-IID007003] Checkin successful with authId: 5559563267000442979, digest: q74wAAKHQTnLNcKR1fGBcQ==, lastCheckinTimestamp: 1551741291000
2019-03-04 15:14:51.354487-0800 app[24344:1709377] 5.17.0 - [Firebase/InstanceID][I-IID005004] Successfully got checkin credentials
2019-03-04 15:14:51.354682-0800 app[24344:1709377] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:14:51.363534-0800 app[24344:1709377] 5.17.0 - [Firebase/InstanceID][I-IID005002] Checkin success.
2019-03-04 15:14:51.971721-0800 app[24344:1709337] 5.17.0 - [Firebase/InstanceID][I-IID013002] Removed cached checkin preferences from Keychain.
2019-03-04 15:14:51.972057-0800 app[24344:1709337] 5.17.0 - [Firebase/InstanceID][I-IID013006] App reset detected. Will delete server registrations.
2019-03-04 15:14:51.972308-0800 app[24344:1709337] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:14:51.974908-0800 app[24344:1709337] 5.17.0 - [Firebase/InstanceID][I-IID021000] Unregister request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5649416461976195065&plat=2&app=app.ios&app_ver=1.1.13_dev_100&X-cliv=fiid-3.3.1&delete=true
2019-03-04 15:14:52.035407-0800 app[24344:1709344] 5.17.0 - [Firebase/InstanceID][I-IID003012] Provisioning profile has specifically provisioned devices, most likely a Dev profile.
2019-03-04 15:14:52.035737-0800 app[24344:1709344] 5.17.0 - [Firebase/InstanceID][I-IID003013] APNS Environment in profile: development
2019-03-04 15:14:52.079553-0800 app[24344:1709344] 5.17.0 - [Firebase/InstanceID][I-IID014007] Successfully deleted GCM server registrations on app reset
2019-03-04 15:14:52.080374-0800 app[24344:1709344] 5.17.0 - [Firebase/InstanceID][I-IID021000] Unregister request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5559563267000442979&X-scope=*&plat=2&app=app.ios&app_ver=1.1.13_dev_100&X-cliv=fiid-3.3.1&delete=true&iid-operation=delete&sender=*&appid=eMOR5zgHp14
2019-03-04 15:14:52.167256-0800 app[24344:1709343] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:14:52.177828-0800 app[24344:1709343] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:14:52.178501-0800 app[24344:1709343] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:14:52.673099-0800 app[24344:1709350] 5.17.0 - [Firebase/InstanceID][I-IID007006] Checkin parameters: {
2019-03-04 15:14:52.910201-0800 app[24344:1709336] 5.17.0 - [Firebase/InstanceID][I-IID007002] Invalid last checkin timestamp in future.
2019-03-04 15:14:52.912411-0800 app[24344:1709336] 5.17.0 - [Firebase/InstanceID][I-IID007003] Checkin successful with authId: 4969388653978385422, digest: BTwyFdaST753uwK/XghbfA==, lastCheckinTimestamp: 1551741292000
2019-03-04 15:14:52.912717-0800 app[24344:1709336] 5.17.0 - [Firebase/InstanceID][I-IID005004] Successfully got checkin credentials
2019-03-04 15:14:52.912797-0800 app[24344:1709336] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:14:52.919281-0800 app[24344:1709343] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:14:52.920395-0800 app[24344:1709343] 5.17.0 - [Firebase/InstanceID][I-IID014000] Fetch new token for authorizedEntity: 344034181945, scope: *
2019-03-04 15:14:52.920578-0800 app[24344:1709343] 5.17.0 - [Firebase/InstanceID][I-IID020000] Register request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=4969388653978385422&X-scope=*&plat=2&app=app.ios&app_v2019-03-04 15:14:53.087935-0800 app[24344:1709343] 5.17.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:14:53.092344-0800 app[24344:1709343] 5.17.0 - [Firebase/InstanceID][I-IID014001] Token fetch successful, token: [TOKEN_2], authorizedEntity: 344034181945, scope:*
2019-03-04 15:14:53.106432-0800 app[24344:1709343] 5.17.0 - [Firebase/InstanceID][I-IID003010] Successfully fetched default token.
2019-03-04 15:14:53.106486-0800 app[24344:1709343] 5.17.0 - [Firebase/InstanceID][I-IID003008] Got default token [TOKEN_2]

As you see it triggered refreshing and registering a new token on Google servers again.

After doing this once in all next launches of the app I can see these logs:

2019-03-04 15:18:27.960389-0800 app[24355:1710247] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:18:27.988143-0800 app[24355:1710258] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:18:27.994512-0800 app[24355:1710261] 5.17.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
2019-03-04 15:18:27.994557-0800 app[24355:1710261] 5.17.0 - [Firebase/InstanceID][I-IID009000] No keypair info is retrieved with tag com.google.iid-|K|
2019-03-04 15:18:28.990470-0800 app[24355:1710275] 5.17.0 - [Firebase/InstanceID][I-IID003012] Provisioning profile has specifically provisioned devices, most likely a Dev profile.
2019-03-04 15:18:28.990561-0800 app[24355:1710275] 5.17.0 - [Firebase/InstanceID][I-IID003013] APNS Environment in profile: development

It looks like fine, and no reset detection and unregistering is happening.

I personally think that is a very serious issue and it should be fixed ASAP. Previously we were using Firebase 4.13.0 and it was working perfectly. After updating to Firebase 5.17.0 (due to other Firebase issue fixed in updates) push notifications stop working without using the workaround.

@ranipanimisha94
Copy link

ranipanimisha94 commented Mar 5, 2019

I am also facing this issue. Receiving notifications only once & not receiving when second time app launch.

Any one have solution for this issue ??

@xiao99xiao
Copy link

xiao99xiao commented Mar 5, 2019

Seems currently the best solution is to downgrade Firebase to 5.16.0
[Update] Maybe 5.15.0 is a better choice.

@charlotteliang
Copy link
Contributor

charlotteliang commented Mar 5, 2019

Sorry for the inconvenience. The Firebase 5.18.0 has just released and should fix the issue. Can you update and try it again?

@paulb777 paulb777 added this to the 5.18.0 milestone Mar 5, 2019
@paulb777 paulb777 closed this as completed Mar 5, 2019
@ranipanimisha94
Copy link

Updated Firebase 5.18.0 but still didn't work.

@zohaib-ehsan
Copy link

zohaib-ehsan commented Mar 6, 2019

@xiao99xiao I faced this issue in 5.16. I was using 5.16. Then first I updated to 5.17 it did not help. Downgrading to 5.15 solved my issue

@xiao99xiao
Copy link

@zohaib-ehsan Actually I downgraded to 5.15 too, but maybe you should check the order you call FirebaseApp.configure() Messaging.messaging().delegate = self and UIApplication.shared.registerForRemoteNotifications(). Just to make sure func messaging(_ messaging: Messaging, didReceiveRegistrationToken fcmToken: String) is actually called when the token changed.

@zohaib-ehsan
Copy link

zohaib-ehsan commented Mar 6, 2019

@xiao99xiao Yes you are right. I changed the order also. Calling registerRemoteNotifications before fcm methods. But did not helped me. So I downgraded to 5.15. Check this.Downgrading solved this guy problem also. https://github.com/firebase/firebase-ios-sdk/issues/2365

@charlotteliang
Copy link
Contributor

@ranipanimisha94 Can you show us the log or reproduce steps after you upgrade to 5.18.0?
Make sure you update to the latest InstanceID:

Using FirebaseInstanceID (3.6.0)

@ranipanimisha94
Copy link

ranipanimisha94 commented Mar 6, 2019

@chliangGoogle for Firebase push notification reproduce steps is just like this

  1. Re-Intsall app from xcode and then got fcm token after that I tried from Firebase console and also from my server side
  2. Sending notification and also receiving notifications properly.
  3. Now I kill my app and again launch and checked my fcm token same as previous one.
  4. Now try to send from Firebase console I am not getting notification.

This above steps every time I am trying same problem.

And I have checked my FirebaseInstanceId is 3.6.0

@ranipanimisha94
Copy link

ranipanimisha94 commented Mar 6, 2019

@xiao99xiao Thanksx. Downgraded my Firebase to 5.15 solved my problem but when my fcm token refresh with new one again facing same issue stop receiving push notification.

Do you have any idea regarding this ?

@xiao99xiao
Copy link

xiao99xiao commented Mar 6, 2019

@ranipanimisha94 I think you could refer to this: #2438 (comment)

@ranipanimisha94
Copy link

ranipanimisha94 commented Mar 6, 2019

@xiao99xiao I have checked your code. My code is same as you explained. But when Token Change stop getting notification.

@Sunrise17
Copy link
Author

Sunrise17 commented Mar 6, 2019

@chliangGoogle , I made a clean pod install in my Project with having Firebase (5.18.0) and FirebaseInstanceId (3.6.0). Unfortunately, same issue still goes on...You can find the list as follows mentioning the updated versions of Pods used in the Project.

UPDATED Component version: * Core 5.18.0, Messaging 3.3.2
CocoaPods 1.6.0
Using Bolts (1.9.0)
Using BoringSSL-GRPC (0.0.2)
Using Firebase (5.18.0)
Using FirebaseAnalytics (5.7.0)
Using FirebaseAnalyticsInterop (1.2.0)
Using FirebaseAuth (5.4.0)
Using FirebaseAuthInterop (1.0.0)
Using FirebaseCore (5.3.1)
Using FirebaseDatabase (5.1.0)
Using FirebaseFirestore (1.0.2)
Using FirebaseInstanceID (3.6.0)
Using FirebaseMessaging (3.3.2)
Using GTMSessionFetcher (1.2.1)
Using Google-Mobile-Ads-SDK (7.40.0)
Using GoogleAppMeasurement (5.7.0)
Using GoogleUtilities (5.3.7)
Using Protobuf (3.7.0)
Using gRPC-C++ (0.0.6)
Using gRPC-Core (1.17.0)
Using leveldb-library (1.20)
Using nanopb (0.3.901)

@paulb777 paulb777 reopened this Mar 6, 2019
@charlotteliang
Copy link
Contributor

@Sunrise17 Can you show us the log or reproduce steps after you upgrade to 5.18.0? The issue should be resolved given @ranipanimisha94's log that token stop refreshing every app starts.

@charlotteliang
Copy link
Contributor

@ranipanimisha94 The original issue(5.17.0) was caused by token invalidated every time app restart, which is why you can't receive notification. Form your latest reproduce steps, seems like that issue has been resolved because you are getting the same token. Also seems like you console can't send the notification even if you downgrade to 5.15.0, so I think the reason you can't receive notification might be a separate issue.

I'm able to reproduce the issue in 5.17.0, but I can't reproduce for 5.18.0, notification delivery should work once you upgrade to 5.18.0.

@Sunrise17
Copy link
Author

Sunrise17 commented Mar 7, 2019

@chliangGoogle , please find attached logs regarding to FirebaseInstanceID below, consisting 1st and 2nd launch of the app. Please note that during the 2nd start of the app, it is using the same fcmToken which received from 1st launch.

- Log from 1st launch of the app with successful token registration that allows push notification to work well.

`2019-03-07 09:53:53.738925+0300 [4770:636728] 5.18.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
acct = "com.my.app";
class = genp;
gena = "com.google.iid-tokens";
"m_Limit" = "m_LimitAll";
"r_Attributes" = 1;
"r_Data" = 1;
svce = "7040823024517:*";
}
2019-03-07 09:53:54.467208+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID007002] Invalid last checkin timestamp in future.
2019-03-07 09:53:54.467955+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID007003] Checkin successful with authId: 5627202339924109063, digest: FkqXrusIGOfS7ItcODZksw==, lastCheckinTimestamp: 1551941634000
2019-03-07 09:53:54.471472+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID005004] Successfully got checkin credentials
2019-03-07 09:53:54.474706+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
acct = "com.my.app";
class = genp;
gena = "com.google.iid";
svce = "com.google.iid.checkin";
}
2019-03-07 09:53:54.476425+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID005002] Checkin success.

2019-03-07 09:53:56.888281+0300 [4770:636784] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
acct = "com.google.iid.checkin-account";
class = genp;
gena = "com.google.iid";
svce = "com.google.iid.checkin-service";
}

2019-03-07 09:53:56.936745+0300 [4770:636784] 5.18.0 - [Firebase/InstanceID][I-IID013002] Removed cached checkin preferences from Keychain.
2019-03-07 09:53:56.937539+0300 [4770:636784] 5.18.0 - [Firebase/InstanceID][I-IID013006] App reset detected. Will delete server registrations.
2019-03-07 09:53:57.071346+0300 [4770:636773] 5.18.0 - [GoogleUtilities/AppDelegateSwizzler][I-SWZ001008] Successfully created App Delegate Proxy automatically. To disable the proxy, set the flag GoogleUtilitiesAppDelegateProxyEnabled to NO (Boolean) in the Info.plist
2019-03-07 09:53:57.071646+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID014000] Fetch new token for authorizedEntity: 7040823024517, scope: *

2019-03-07 09:53:57.072411+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
atag = <636f6d2e 676f6f67 6c652e69 69642d7c 507c>;
class = keys;
type = 42;
}

2019-03-07 09:53:57.073579+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID003012] Provisioning profile has specifically provisioned devices, most likely a Dev profile.
2019-03-07 09:53:57.073720+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID003013] APNS Environment in profile: development
2019-03-07 09:53:57.073790+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
acct = "com.my.app";
class = genp;
gena = "com.google.iid-tokens";
"m_Limit" = "m_LimitAll";
"r_Attributes" = 1;
"r_Data" = 1;
}

2019-03-07 09:53:57.074677+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
atag = <636f6d2e 676f6f67 6c652e69 69642d7c 4b7c>;
class = keys;
type = 42;
}
2019-03-07 09:53:57.075225+0300 [4770:636773] 5.18.0 - [Firebase/InstanceID][I-IID021000] Unregister request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5514494680253659366&plat=2&app=com.my.app&app_ver=1.0&X-cliv=fiid-3.3.2&delete=true

2019-03-07 09:53:57.127497+0300 [4770:636766] 5.18.0 - [Firebase/InstanceID][I-IID014007] Successfully deleted GCM server registrations on app reset
2019-03-07 09:53:57.129625+0300 [4770:636766] 5.18.0 - [Firebase/InstanceID][I-IID020000] Register request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5627202339924109063&X-scope=*&plat=2&app=com.my.app&app_ver=1.0&X-cliv=fiid-3.3.2&sender=7040823024517&X-subtype=7040823024517&appid=cDXyI4ELOBA&gmp_app_id=1:7040823024517:ios:0fe99665b82779fb

2019-03-07 09:53:57.470592+0300 [4770:636784] 5.18.0 - [Firebase/InstanceID][I-IID014001] Token fetch successful, token: J648hnnx9:APA91bG_H7Zeksdffweer345zM3-DyQsdfJJJH8983Nst9cA4vRGQuWXL0-XLLklads00JJhhxx00x0za0FOaWEZlhQWLFa9wci6LmhMkarPTIadPuaV0zxV439HZ9-2Lm0Xvw9BR24, authorizedEntity: 7040823024517, scope:*
2019-03-07 09:53:57.472591+0300 [4770:636784] 5.18.0 - [Firebase/InstanceID][I-IID003016] Received APNS token while fetching default token. Refetching default token.
2019-03-07 09:53:57.474124+0300 [4770:636784] 5.18.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
atag = <636f6d2e 676f6f67 6c652e69 69642e6b 65797061 69722e70 72697661 74652d63 6f6d2e70 726f626d 696e642e 50726f66 65737369 6f6e616c 73>;
class = keys;
"r_Ref" = 1;
type = 42;
}
2019-03-07 09:53:57.475587+0300 [4770:636784] 5.18.0 - [Firebase/InstanceID][I-IID009000] No keypair info is retrieved with tag com.google.iid.keypair.private-com.my.app

2019-03-07 09:54:00.588440+0300 [4770:636765] 5.18.0 - [Firebase/InstanceID][I-IID014000] Fetch new token for authorizedEntity: 7040823024517, scope: *
2019-03-07 09:54:00.589001+0300 [4770:636765] 5.18.0 - [Firebase/InstanceID][I-IID020000] Register request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5627202339924109063&X-scope=*&plat=2&app=com.my.app&app_ver=1.0&X-cliv=fiid-3.3.2&sender=7040823024517&X-subtype=7040823024517&appid=cDXyI4ELOBA&apns_token=s_a8add06475107efcf2bda41b9f88fb2902786ecfbba842bce35dd7b222a639be&gmp_app_id=1:7040823024517:ios:0fe99665b82779fb

2019-03-07 09:54:00.826734+0300 [4770:636766] 5.18.0 - [Firebase/InstanceID][I-IID014001] Token fetch successful, token: J648hnnx9:APA91bG_H7Zeksdffweer345zM3-DyQsdfJJJH8983Nst9cA4vRGQuWXL0-XLLklads00JJhhxx00x0za0FOaWEZlhQWLFa9wci6LmhMkarPTIadPuaV0zxV439HZ9-2Lm0Xvw9BR24, authorizedEntity: 7040823024517, scope:*
2019-03-07 09:54:00.827412+0300 [4770:636766] 5.18.0 - [Firebase/InstanceID][I-IID003010] Successfully fetched default token.
2019-03-07 09:54:00.827543+0300 [4770:636766] 5.18.0 - [Firebase/InstanceID][I-IID003008] Got default token J648hnnx9:APA91bG_H7Zeksdffweer345zM3-DyQsdfJJJH8983Nst9cA4vRGQuWXL0-XLLklads00JJhhxx00x0za0FOaWEZlhQWLFa9wci6LmhMkarPTIadPuaV0zxV439HZ9-2Lm0Xvw9BR24
`

- Log from 2nd launch of the app, push notification stopped to respond.

`2019-03-07 10:06:46.228656+0300 [4792:639141] 5.18.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
atag = <636f6d2e 676f6f67 6c652e69 69642d7c 4b7c>;
class = keys;
"r_Ref" = 1;
type = 42;
}
2019-03-07 10:06:46.230708+0300 [4792:639141] 5.18.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
atag = <636f6d2e 676f6f67 6c652e69 69642d7c 507c>;
class = keys;
"r_Ref" = 1;
type = 42;
}
2019-03-07 10:06:46.231289+0300 [4792:639141] 5.18.0 - [Firebase/InstanceID][I-IID009000] No keypair info is retrieved with tag com.google.iid-|K|
2019-03-07 10:06:46.231402+0300 [4792:639141] 5.18.0 - [Firebase/Messaging][I-FCM002000] FIRMessaging library version 3.3.2
2019-03-07 10:06:46.231474+0300 [4792:639141] 5.18.0 - [GULReachability][I-REA902003] Monitoring the network status
2019-03-07 10:06:46.235296+0300 [4792:639141] 5.18.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.

2019-03-07 10:06:46.531952+0300 [4792:639107] 5.18.0 - [Firebase/InstanceID][I-IID007002] Invalid last checkin timestamp in future.
2019-03-07 10:06:46.539857+0300 [4792:639107] 5.18.0 - [Firebase/InstanceID][I-IID007003] Checkin successful with authId: 4904463852646131602, digest: gL1Zsg3NS4IW4rHHCRL+Xg==, lastCheckinTimestamp: 1551942406000
2019-03-07 10:06:46.547951+0300 [4792:639107] 5.18.0 - [Firebase/InstanceID][I-IID005004] Successfully got checkin credentials

2019-03-07 10:06:46.565783+0300 [4792:639107] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
acct = "com.my.app";
class = genp;
gena = "com.google.iid";
svce = "com.google.iid.checkin";
}
2019-03-07 10:06:46.568430+0300 [4792:639107] 5.18.0 - [Firebase/InstanceID][I-IID005002] Checkin success.

2019-03-07 10:06:48.300901+0300 [4792:639156] 5.18.0 - [Firebase/InstanceID][I-IID013002] Removed cached checkin preferences from Keychain.
2019-03-07 10:06:48.301385+0300 [4792:639156] 5.18.0 - [Firebase/InstanceID][I-IID013006] App reset detected. Will delete server registrations.

//(print in AppDelegate: func messaging(_ messaging: Messaging, didReceiveRegistrationToken fcmToken: String))
Firebase registration token: J648hnnx9:APA91bG_H7Zeksdffweer345zM3-DyQsdfJJJH8983Nst9cA4vRGQuWXL0-XLLklads00JJhhxx00x0za0FOaWEZlhQWLFa9wci6LmhMkarPTIadPuaV0zxV439HZ9-2Lm0Xvw9BR24

2019-03-07 10:06:48.583463+0300 [4792:639156] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
acct = "com.google.iid.checkin-account";
class = genp;
gena = "com.google.iid";
svce = "com.google.iid.checkin-service";
}
2019-03-07 10:06:48.597023+0300 [4792:639156] 5.18.0 - [Firebase/InstanceID][I-IID021000] Unregister request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5627202339924109063&plat=2&app=com.my.app&app_ver=1.0&X-cliv=fiid-3.3.2&delete=true
2019-03-07 10:06:48.598679+0300 [4792:639156] 5.18.0 - [GoogleUtilities/AppDelegateSwizzler][I-SWZ001008] Successfully created App Delegate Proxy automatically. To disable the proxy, set the flag GoogleUtilitiesAppDelegateProxyEnabled to NO (Boolean) in the Info.plist

2019-03-07 10:06:48.678833+0300 [4792:639107] 5.18.0 - [Firebase/InstanceID][I-IID003012] Provisioning profile has specifically provisioned devices, most likely a Dev profile.
2019-03-07 10:06:48.679358+0300 [4792:639107] 5.18.0 - [Firebase/InstanceID][I-IID003013] APNS Environment in profile: development

2019-03-07 10:06:48.830406+0300 [4792:639182] 5.18.0 - [Firebase/InstanceID][I-IID014007] Successfully deleted GCM server registrations on app reset
`

@petergzli
Copy link

@Sunrise17 Can you show me how to gather these logs too? I'm having the same issue on my app and want to share my logs too for extra data.

@Sunrise17
Copy link
Author

Sunrise17 commented Mar 7, 2019

@petergzli , you can add -FIRDebugEnabled into "Arguments Passed on Launch" in Xcode Edit schemes.
ekran resmi 2019-03-07 11 02 13
In addition, do not forget to remove "OS_ACTIVITY_MODE disable (if it has)" from environment Variables. It should be enabled.

@petergzli
Copy link

petergzli commented Mar 7, 2019

Hey guys sharing my logs here too. I haven't been getting push notifications at all for past couple weeks on my device. This log is pulled from the latest Firebase version:

Firebase 5.18.0
FirebaseCore 5.3.1
FirebaseInstanceID 3.6.0
FirebaseMessaging 3.3.2

Same exact issue on my iPhone 7, I get the notRegistered error every time. It's the same on my iPodtouch 6G

2019-03-07 00:16:22.578106-0800 unlocked[3053:259029] 5.18.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
acct = "com.unlocked.test";
class = genp;
gena = "com.google.iid-tokens";
"m_Limit" = "m_LimitAll";
"r_Attributes" = 1;
"r_Data" = 1;
svce = "414034688860:*";
}
2019-03-07 00:16:22.578815-0800 unlocked[3053:259029] 5.18.0 - [Firebase/Messaging][I-FCM002000] FIRMessaging library version 3.3.2

2019-03-07 00:16:22.605040-0800 unlocked[3053:259047] 5.18.0 - [Firebase/InstanceID][I-IID007006] Checkin parameters: {
checkin = {
iosbuild = {
model = "iPhone9,1";
"os_version" = "IOS_12.1.4";
};
"last_checkin_msec" = 0;
type = 2;
"user_number" = 0;
};
digest = "";
fragment = 0;
id = 0;
locale = "en_US";
"logging_id" = 3361212234;
"security_token" = 0;
timezone = "America/Los_Angeles";
"user_serial_number" = 0;
version = 2;
}
2019-03-07 00:16:22.614519-0800 unlocked[3053:259047] 5.18.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.

2019-03-07 00:16:22.966158-0800 unlocked[3053:259029] 5.18.0 - [Firebase/InstanceID][I-IID007002] Invalid last checkin timestamp in future.
2019-03-07 00:16:22.966380-0800 unlocked[3053:259029] 5.18.0 - [Firebase/InstanceID][I-IID007003] Checkin successful with authId: 5547419840127956014, digest: fOL8q2/n+MXpYrWoJ5RXzA==, lastCheckinTimestamp: 1551946582000
2019-03-07 00:16:22.966757-0800 unlocked[3053:259029] 5.18.0 - [Firebase/InstanceID][I-IID005004] Successfully got checkin credentials
2019-03-07 00:16:22.966879-0800 unlocked[3053:259029] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
acct = "com.unlocked.test";
class = genp;
gena = "com.google.iid";
svce = "com.google.iid.checkin";
}
2019-03-07 00:16:23.252913-0800 unlocked[3053:259031] 5.18.0 - [Firebase/InstanceID][I-IID005002] Checkin success.

2019-03-07 00:16:24.939402-0800 unlocked[3053:259047] 5.18.0 - [Firebase/InstanceID][I-IID013002] Removed cached checkin preferences from Keychain.
2019-03-07 00:16:24.940215-0800 unlocked[3053:259047] 5.18.0 - [Firebase/InstanceID][I-IID013006] App reset detected. Will delete server registrations.
2019-03-07 00:16:24.940539-0800 unlocked[3053:259047] 5.18.0 - [GoogleUtilities/AppDelegateSwizzler][I-SWZ001008] Successfully created App Delegate Proxy automatically. To disable the proxy, set the flag GoogleUtilitiesAppDelegateProxyEnabled to NO (Boolean) in the Info.plist
2019-03-07 00:16:24.941084-0800 unlocked[3053:259047] 5.18.0 - [Firebase/InstanceID][I-IID021000] Unregister request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5010166615553950464&plat=2&app=com.unlocked.test&app_ver=3.3.20&X-cliv=fiid-3.3.2&delete=true
2019-03-07 00:16:24.941580-0800 unlocked[3053:259047] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
acct = "com.google.iid.checkin-account";
class = genp;
gena = "com.google.iid";
svce = "com.google.iid.checkin-service";
}

2019-03-07 00:16:25.032083-0800 unlocked[3053:259047] 5.18.0 - [Firebase/InstanceID][I-IID014000] Fetch new token for authorizedEntity: 414034688860, scope: *
2019-03-07 00:16:25.032297-0800 unlocked[3053:259047] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
atag = <636f6d2e 676f6f67 6c652e69 69642d7c 507c>;
class = keys;
type = 42;
}
2019-03-07 00:16:25.032694-0800 unlocked[3053:259047] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
atag = <636f6d2e 676f6f67 6c652e69 69642d7c 4b7c>;
class = keys;
type = 42;
}

2019-03-07 00:16:25.072701-0800 unlocked[3053:259031] 5.18.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
atag = <636f6d2e 676f6f67 6c652e69 69642e6b 65797061 69722e70 72697661 74652d63 6f6d2e75 6e6c6f63 6b65642e 74657374>;
class = keys;
"r_Ref" = 1;
type = 42;
}
2019-03-07 00:16:25.074455-0800 unlocked[3053:259047] 5.18.0 - [Firebase/InstanceID][I-IID009000] No keypair info is retrieved with tag com.google.iid.keypair.private-com.unlocked.test

2019-03-07 00:16:25.206951-0800 unlocked[3053:259029] 5.18.0 - [Firebase/InstanceID][I-IID014007] Successfully deleted GCM server registrations on app reset
2019-03-07 00:16:25.206990-0800 unlocked[3053:259029] 5.18.0 - [Firebase/InstanceID][I-IID020000] Register request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5547419840127956014&X-scope=*&plat=2&app=com.unlocked.test&app_ver=3.3.20&X-cliv=fiid-3.3.2&sender=414034688860&X-subtype=414034688860&appid=dh6cFpQF1KQ&gmp_app_id=1:414034688860:ios:ac6c23965a65ac50

2019-03-07 00:16:25.951636-0800 unlocked[3053:259105] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
acct = "com.unlocked.test";
class = genp;
gena = "com.google.iid-tokens";
svce = "414034688860:";
}
2019-03-07 00:16:25.956089-0800 unlocked[3053:259031] 5.18.0 - [Firebase/InstanceID][I-IID014001] Token fetch successful, token: dh6cFpQF1KQ:APA91bHeIPuRwXbfZ8ClOFLVTqXgVoZCkHATMRrYZNhJepM94oZPqJCNLyALYk-amZAsKeP5FMUsTlzfHAic6aNi5uYS1kTJODaINBZTxEzpXlm6grBkxT-qvDWoARFMPe3fbqRUvmP5, authorizedEntity: 414034688860, scope:

2019-03-07 00:16:25.957139-0800 unlocked[3053:259031] 5.18.0 - [Firebase/InstanceID][I-IID003010] Successfully fetched default token.
2019-03-07 00:16:25.957356-0800 unlocked[3053:259031] 5.18.0 - [Firebase/InstanceID][I-IID003008] Got default token dh6cFpQF1KQ:APA91bHeIPuRwXbfZ8ClOFLVTqXgVoZCkHATMRrYZNhJepM94oZPqJCNLyALYk-amZAsKeP5FMUsTlzfHAic6aNi5uYS1kTJODaINBZTxEzpXlm6grBkxT-qvDWoARFMPe3fbqRUvmP5
2019-03-07 00:16:25.964550-0800 unlocked[3053:259031] 5.18.0 - [Firebase/Analytics][I-ACS023072] Event logged. Event name, event params: user_engagement (_e), {
engagement_time_msec (_et) = 1;
firebase_debug (_dbg) = 1;
firebase_event_origin (_o) = auto;
ga_realtime (_r) = 1;
}

2019-03-07 00:16:35.673618-0800 unlocked[3053:259105] 5.18.0 - [Firebase/InstanceID][I-IID003012] Provisioning profile has specifically provisioned devices, most likely a Dev profile.
2019-03-07 00:16:35.674252-0800 unlocked[3053:259105] 5.18.0 - [Firebase/InstanceID][I-IID003013] APNS Environment in profile: development
2019-03-07 00:16:35.682231-0800 unlocked[3053:259185] 5.18.0 - [Firebase/InstanceID][I-IID014011] Invalidating cached token for 414034688860 () due to APNs token change.
2019-03-07 00:16:35.682522-0800 unlocked[3053:259185] 5.18.0 - [Firebase/InstanceID][I-IID014000] Fetch new token for authorizedEntity: 414034688860, scope: *
2019-03-07 00:16:35.684612-0800 unlocked[3053:259185] 5.18.0 - [Firebase/InstanceID][I-IID020000] Register request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5547419840127956014&X-scope=
&plat=2&app=com.unlocked.test&app_ver=3.3.20&X-cliv=fiid-3.3.2&sender=414034688860&X-subtype=414034688860&appid=dh6cFpQF1KQ&apns_token=s_fe4c5e2be46121c79890f241d6d4a789b25de758b25453ed8abc91ae191cfb51&gmp_app_id=1:414034688860:ios:ac6c23965a65ac50
2019-03-07 00:16:35.829462-0800 unlocked[3053:259185] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
acct = "com.unlocked.test";
class = genp;
gena = "com.google.iid-tokens";
svce = "414034688860:";
}
2019-03-07 00:16:35.830726-0800 unlocked[3053:259185] 5.18.0 - [Firebase/InstanceID][I-IID014001] Token fetch successful, token: dh6cFpQF1KQ:APA91bHeIPuRwXbfZ8ClOFLVTqXgVoZCkHATMRrYZNhJepM94oZPqJCNLyALYk-amZAsKeP5FMUsTlzfHAic6aNi5uYS1kTJODaINBZTxEzpXlm6grBkxT-qvDWoARFMPe3fbqRUvmP5, authorizedEntity: 414034688860, scope:

2019-03-07 00:16:35.831075-0800 unlocked[3053:259185] 5.18.0 - [Firebase/InstanceID][I-IID003010] Successfully fetched default token.
2019-03-07 00:16:35.831169-0800 unlocked[3053:259185] 5.18.0 - [Firebase/InstanceID][I-IID003008] Got default token dh6cFpQF1KQ:APA91bHeIPuRwXbfZ8ClOFLVTqXgVoZCkHATMRrYZNhJepM94oZPqJCNLyALYk-amZAsKeP5FMUsTlzfHAic6aNi5uYS1kTJODaINBZTxEzpXlm6grBkxT-qvDWoARFMPe3fbqRUvmP5

AFTER RESTART APP BELOW

2019-03-07 00:22:20.789451-0800 unlocked[3081:260596] 5.18.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
atag = <636f6d2e 676f6f67 6c652e69 69642d7c 4b7c>;
class = keys;
"r_Ref" = 1;
type = 42;
}
2019-03-07 00:22:20.789963-0800 unlocked[3081:260596] 5.18.0 - [Firebase/InstanceID][I-IID023000] No info is retrieved from Keychain OSStatus: -25300 with the keychain query {
atag = <636f6d2e 676f6f67 6c652e69 69642d7c 507c>;
class = keys;
"r_Ref" = 1;
type = 42;
}
2019-03-07 00:22:20.792146-0800 unlocked[3081:260596] 5.18.0 - [Firebase/InstanceID][I-IID009000] No keypair info is retrieved with tag com.google.iid-|K|
2019-03-07 00:22:20.792270-0800 unlocked[3081:260596] 5.18.0 - [Firebase/Messaging][I-FCM002000] FIRMessaging library version 3.3.2

2019-03-07 00:22:20.792414-0800 unlocked[3081:260596] 5.18.0 - [Firebase/InstanceID][I-IID007006] Checkin parameters: {
checkin = {
iosbuild = {
model = "iPhone9,1";
"os_version" = "IOS_12.1.4";
};
"last_checkin_msec" = 0;
type = 2;
"user_number" = 0;
};
digest = "";
fragment = 0;
id = 0;
locale = "en_US";
"logging_id" = 3742283978;
"security_token" = 0;
timezone = "America/Los_Angeles";
"user_serial_number" = 0;
version = 2;
}
2019-03-07 00:22:20.792476-0800 unlocked[3081:260596] 5.18.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.

2019-03-07 00:22:21.093440-0800 unlocked[3081:260587] 5.18.0 - [Firebase/InstanceID][I-IID007002] Invalid last checkin timestamp in future.
2019-03-07 00:22:21.094619-0800 unlocked[3081:260587] 5.18.0 - [Firebase/InstanceID][I-IID007003] Checkin successful with authId: 5118654683944685981, digest: GCtFXrJgRd0EzAMGNFIuOg==, lastCheckinTimestamp: 1551946941000
2019-03-07 00:22:21.094926-0800 unlocked[3081:260587] 5.18.0 - [Firebase/InstanceID][I-IID005004] Successfully got checkin credentials
2019-03-07 00:22:21.095037-0800 unlocked[3081:260587] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
acct = "com.unlocked.test";
class = genp;
gena = "com.google.iid";
svce = "com.google.iid.checkin";
}
2019-03-07 00:22:21.104459-0800 unlocked[3081:260588] 5.18.0 - [Firebase/InstanceID][I-IID005002] Checkin success.

2019-03-07 00:22:21.836621-0800 unlocked[3081:260658] 5.18.0 - [Firebase/InstanceID][I-IID013002] Removed cached checkin preferences from Keychain.
2019-03-07 00:22:21.836770-0800 unlocked[3081:260658] 5.18.0 - [Firebase/InstanceID][I-IID013006] App reset detected. Will delete server registrations.
2019-03-07 00:22:21.836906-0800 unlocked[3081:260658] 5.18.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
acct = "com.google.iid.checkin-account";
class = genp;
gena = "com.google.iid";
svce = "com.google.iid.checkin-service";
}
2019-03-07 00:22:21.837291-0800 unlocked[3081:260658] 5.18.0 - [GoogleUtilities/AppDelegateSwizzler][I-SWZ001008] Successfully created App Delegate Proxy automatically. To disable the proxy, set the flag GoogleUtilitiesAppDelegateProxyEnabled to NO (Boolean) in the Info.plist

2019-03-07 00:22:21.840845-0800 unlocked[3081:260658] 5.18.0 - [Firebase/InstanceID][I-IID021000] Unregister request to https://fcmtoken.googleapis.com/register content: X-osv=12.1.4&device=5547419840127956014&plat=2&app=com.unlocked.test&app_ver=3.3.20&X-cliv=fiid-3.3.2&delete=true

2019-03-07 00:22:22.091715-0800 unlocked[3081:260658] 5.18.0 - [Firebase/InstanceID][I-IID014007] Successfully deleted GCM server registrations on app reset

@keech
Copy link

keech commented Apr 8, 2019

@chliangGoogle Sorry for respnse.
It seems that the problem has not been solved yet.

I attached log file.
app.log

My pod is below

  pod 'Firebase/Core'
  pod 'Firebase/Messaging'
  pod 'FirebaseInstanceID'

and Podfile.lock is

  - Firebase/Core (5.20.1):
    - Firebase/CoreOnly
    - FirebaseAnalytics (= 5.8.0)
  - Firebase/CoreOnly (5.20.1):
    - FirebaseCore (= 5.4.1)
  - Firebase/Messaging (5.20.1):
    - Firebase/CoreOnly
    - FirebaseMessaging (= 3.5.0)
  - FirebaseAnalytics (5.8.0):
    - FirebaseCore (~> 5.4)
    - FirebaseInstanceID (~> 3.8)
    - GoogleAppMeasurement (= 5.8.0)
    - GoogleUtilities/AppDelegateSwizzler (~> 5.2)
    - GoogleUtilities/MethodSwizzler (~> 5.2)
    - GoogleUtilities/Network (~> 5.2)
    - "GoogleUtilities/NSData+zlib (~> 5.2)"
    - nanopb (~> 0.3)
  - FirebaseAnalyticsInterop (1.2.0)
  - FirebaseCore (5.4.1):
    - GoogleUtilities/Environment (~> 5.2)
    - GoogleUtilities/Logger (~> 5.2)
  - FirebaseInstanceID (3.8.1):
    - FirebaseCore (~> 5.2)
    - GoogleUtilities/Environment (~> 5.2)
    - GoogleUtilities/UserDefaults (~> 5.2)
  - FirebaseMessaging (3.5.0):
    - FirebaseAnalyticsInterop (~> 1.1)
    - FirebaseCore (~> 5.2)
    - FirebaseInstanceID (~> 3.6)
    - GoogleUtilities/Environment (~> 5.3)
    - GoogleUtilities/Reachability (~> 5.3)
    - GoogleUtilities/UserDefaults (~> 5.3)
    - Protobuf (~> 3.1)

Are there any hint to solve this problem?

@paulb777 paulb777 reopened this Apr 8, 2019
@charlotteliang
Copy link
Contributor

@keech The debug log shows that
"Invalidating cached token due to Firebase App IID change from 1:1011155874438:ios:36d4535167e7989a to 1:321055892642:ios:d26dde0d744daeb2"

Looks like you switch project during app runs, so token refresh is expected. Did you happen to configure two Firebase project at the same time?

Since you are using multiple firebase project, I suggest you open a separate issue as this is not related to this bug.

@paulb777 paulb777 closed this as completed Apr 8, 2019
@petergzli
Copy link

Hey Guys sorry for being late in the game, but this new Pod is still not working for me. Here are my logs:

2019-04-17 15:11:44.777792-0700 unlocked[629:108650] 5.20.0 - [Firebase/InstanceID][I-IID023000] Info is not found in Keychain. OSStatus: -25300. Keychain query: {
2019-04-17 15:11:44.841727-0700 unlocked[629:108648] 5.20.0 - [Firebase/InstanceID][I-IID007006] Checkin parameters: {
2019-04-17 15:11:44.844517-0700 unlocked[629:108648] 5.20.0 - [Firebase/InstanceID][I-IID005004] Checkin is in progress
2019-04-17 15:11:45.168535-0700 unlocked[629:108648] 5.20.0 - [Firebase/InstanceID][I-IID007002] Invalid last checkin timestamp 2019-04-17 22:11:45 +0000 in future.
2019-04-17 15:11:45.193370-0700 unlocked[629:108648] 5.20.0 - [Firebase/InstanceID][I-IID007003] Checkin successful with authId: 4692205050736925456, digest: ys1JvQzGOIR28e47kmqs6A==, lastCheckinTimestamp: 1555539105000
2019-04-17 15:11:45.194814-0700 unlocked[629:108648] 5.20.0 - [Firebase/InstanceID][I-IID005004] Successfully got checkin credentials
2019-04-17 15:11:45.195784-0700 unlocked[629:108648] 5.20.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-04-17 15:11:47.712175-0700 unlocked[629:108646] 5.20.0 - [Firebase/InstanceID][I-IID013002] Removed cached checkin preferences from Keychain because this is a fresh install.
2019-04-17 15:11:47.712747-0700 unlocked[629:108646] 5.20.0 - [Firebase/InstanceID][I-IID013006] App reset detected. Will delete server registrations.
2019-04-17 15:11:47.714361-0700 unlocked[629:108646] 5.20.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-04-17 15:11:47.714798-0700 unlocked[629:108646] 5.20.0 - [Firebase/InstanceID][I-IID021000] Unregister request to https://fcmtoken.googleapis.com/register content: X-osv=12.2&device=4711118851242491838&plat=2&app=com.unlocked.test&app_ver=3.3.20&X-cliv=fiid-3.5.0&delete=true
2019-04-17 15:11:47.824196-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID014007] Successfully deleted GCM server registrations on app reset
2019-04-17 15:11:48.128708-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID005002] Checkin success.
2019-04-17 15:11:48.129429-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-04-17 15:11:48.130803-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID023000] Info is not found in Keychain. OSStatus: -25300. Keychain query: {
2019-04-17 15:11:48.132259-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID009000] No keypair info is found with tag com.google.iid.keypair.private-com.unlocked.test
2019-04-17 15:11:48.132556-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID003012] Provisioning profile has specifically provisioned devices, most likely a Dev profile.
2019-04-17 15:11:48.134882-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID003013] APNS Environment in profile: development
2019-04-17 15:11:48.874378-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID023000] Info is not found in Keychain. OSStatus: -25300. Keychain query: {
2019-04-17 15:11:48.875983-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-04-17 15:11:48.997312-0700 unlocked[629:108646] 5.20.0 - [Firebase/InstanceID][I-IID014000] Fetch new token for authorizedEntity: 414034688860, scope: *
2019-04-17 15:11:48.998748-0700 unlocked[629:108646] 5.20.0 - [Firebase/InstanceID][I-IID020000] Register request to https://fcmtoken.googleapis.com/register content: X-osv=12.2&device=4692205050736925456&X-scope=&plat=2&app=com.unlocked.test&app_ver=3.3.20&X-cliv=fiid-3.5.0&sender=414034688860&X-subtype=414034688860&appid=cXtNOAdevNI&gmp_app_id=1:414034688860:ios:ac6c23965a65ac50
2019-04-17 15:11:49.235621-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-04-17 15:11:49.263725-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID014001] Token fetch successful, token: cXtNOAdevNI:APA91bE6Pz28zhBVj8MlYPW2bCzG6o3E1j4wgs6BlnTGP1TMWXPXyECN2HYdKQSoKe8RBelBlk_cxxG9ALQGuXDwqBK-8u-zccleQCP0YEN9yXPnzcAz2019-04-17 15:11:49.264823-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID003016] Received APNS token while fetching default token. Refetching default token.
2019-04-17 15:11:49.267267-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID014000] Fetch new token for authorizedEntity: 414034688860, scope: *
2019-04-17 15:11:49.267768-0700 unlocked[629:108718] 5.20.0 - [Firebase/InstanceID][I-IID020000] Register request to https://fcmtoken.googleapis.com/register content: X-osv=12.2&device=4692205050736925456&X-scope=
&plat=2&app=com.unlocked.test&app_ver=3.3.2019-04-17 15:11:49.419705-0700 unlocked[629:108717] 5.20.0 - [Firebase/InstanceID][I-IID014001] Token fetch successful, token: cXtNOAdevNI:APA91bE6Pz28zhBVj8MlYPW2bCzG6o3E1j4wgs6BlnTGP1TMWXPXyECN2HYdKQSoKe8RBelBlk_cxxG9ALQGuXDwqBK-8u-zccleQCP0YEN9yXPnzcAzoCspEi740CCMssWhsc3GxybY, authorizedEntity: 414034688860, scope:*
2019-04-17 15:11:49.421468-0700 unlocked[629:108717] 5.20.0 - [Firebase/InstanceID][I-IID003010] Successfully fetched default token.
2019-04-17 15:11:49.421532-0700 unlocked[629:108717] 5.20.0 - [Firebase/InstanceID][I-IID003008] Got default token cXtNOAdevNI:APA91bE6Pz28zhBVj8MlYPW2bCzG6o3E1j4wgs6BlnTGP1TMWXPXyECN2HYdKQSoKe8RBelBlk_cxxG9ALQGuXDwqBK-8u-zccleQCP0YEN9yXPnzcAzoCspEi740CCMssWhsc3GxybY

AFTER RESTART

2019-04-17 15:12:48.956145-0700 unlocked[634:109400] 5.20.0 - [Firebase/InstanceID][I-IID023000] Info is not found in Keychain. OSStatus: -25300. Keychain query: {
2019-04-17 15:12:49.172649-0700 unlocked[634:109396] 5.20.0 - [Firebase/InstanceID][I-IID023000] Info is not found in Keychain. OSStatus: -25300. Keychain query: {
2019-04-17 15:12:49.174337-0700 unlocked[634:109396] 5.20.0 - [Firebase/InstanceID][I-IID009000] No keypair info is found with tag com.google.iid-|K|
2019-04-17 15:12:49.175034-0700 unlocked[634:109396] 5.20.0 - [Firebase/InstanceID][I-IID009006] There's no legacy keypair so no need to do migration.
2019-04-17 15:12:49.175950-0700 unlocked[634:109396] 5.20.0 - [Firebase/InstanceID][I-IID007006] Checkin parameters: {
2019-04-17 15:12:49.375062-0700 unlocked[634:109396] 5.20.0 - [Firebase/InstanceID][I-IID007002] Invalid last checkin timestamp 2019-04-17 22:12:49 +0000 in future.
2019-04-17 15:12:49.375867-0700 unlocked[634:109396] 5.20.0 - [Firebase/InstanceID][I-IID007003] Checkin successful with authId: 4938561688652818317, digest: nuUSqclhGzgz2zfanPWBZw==, lastCheckinTimestamp: 1555539169000
2019-04-17 15:12:49.377299-0700 unlocked[634:109396] 5.20.0 - [Firebase/InstanceID][I-IID005004] Successfully got checkin credentials
2019-04-17 15:12:49.381624-0700 unlocked[634:109399] 5.20.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-04-17 15:12:51.127437-0700 unlocked[634:109459] 5.20.0 - [Firebase/InstanceID][I-IID013002] Removed cached checkin preferences from Keychain because this is a fresh install.
2019-04-17 15:12:51.128064-0700 unlocked[634:109459] 5.20.0 - [Firebase/InstanceID][I-IID013006] App reset detected. Will delete server registrations.
2019-04-17 15:12:51.131294-0700 unlocked[634:109459] 5.20.0 - [Firebase/InstanceID][I-IID023002] Couldn't delete item from Keychain OSStatus: -25300 with the keychain query {
2019-04-17 15:12:51.133376-0700 unlocked[634:109459] 5.20.0 - [Firebase/InstanceID][I-IID021000] Unregister request to https://fcmtoken.googleapis.com/register content: X-osv=12.2&device=4692205050736925456&plat=2&app=com.unlocked.test&app_ver=3.3.20&X-cliv=fiid-3.5.0&delete=true
2019-04-17 15:12:51.238060-0700 unlocked[634:109459] 5.20.0 - [Firebase/InstanceID][I-IID005002] Checkin success.
2019-04-17 15:12:51.372126-0700 unlocked[634:109396] 5.20.0 - [Firebase/InstanceID][I-IID014007] Successfully deleted GCM server registrations on app reset
2019-04-17 15:12:51.773403-0700 unlocked[634:109411] 5.20.0 - [Firebase/InstanceID][I-IID003012] Provisioning profile has specifically provisioned devices, most likely a Dev profile.
2019-04-17 15:12:51.774007-0700 unlocked[634:109411] 5.20.0 - [Firebase/InstanceID][I-IID003013] APNS Environment in profile: development

@charlotteliang
Copy link
Contributor

@petergzli Did you happen to call [FIRInstanceID instanceID] before [FIRApp configure] during app start?

@petergzli
Copy link

Definitely not

@charlotteliang
Copy link
Contributor

@petergzli Can you try to patch the change #2860 and see if that fixes for you?

@J-L
Copy link

J-L commented Apr 18, 2019

This broke our notifications and makes me wonder why we are using Firebase for notifications.

Repo should have been rolled back immediately after a bug like this is known...

@charlotteliang
Copy link
Contributor

charlotteliang commented Apr 18, 2019

@J-L Apologize for the inconvenience. Unfortunately this issue is not related to a particular PR but a combination of changes on how we package it and race conditions that causing keychain to be corrupted. We also can't reproduce this issue at this point because we can't reproduce with corrupted data. This issue can be resolved if you do a deleteID call to erase the corrupted data. But we are adding preventative fix #2860 to help mitigate the issue for users who still have the corrupted data and don't want to call deleteID. Please share your debug log if you can still reproduce with change #2860.

@whswee-newswav
Copy link

@J-L Apologize for the inconvenience. Unfortunately this issue is not related to a particular PR but a combination of changes on how we package it and race conditions that causing keychain to be corrupted. We also can't reproduce this issue at this point because we can't reproduce with corrupted data. This issue can be resolved if you do a deleteID call to erase the corrupted data. But we are adding preventative fix #2860 to help mitigate the issue for users who still have the corrupted data and don't want to call deleteID. Please share your debug log if you can still reproduce with change #2860.

Any chance to do "DeleteID" from server side?

@charlotteliang
Copy link
Contributor

@whswee-newswav The cause is at the client's keychain which has the corrupted data, so it has to come down to client to remove the old bad data or be able to overwrite the new one. We will roll out a release with #2860 soon to fix this. In the meantime, you can patch the change in #2860 to see if that fixes your issue.

@SephReed
Copy link

SephReed commented May 3, 2019

I'm getting the following errors:

2019-05-03 15:55:24.938717-0500 ChooseHealthApp[5538:1534233] 5.20.0 - [GULReachability][I-REA902003] Monitoring the network status
2019-05-03 15:55:24.945218-0500 ChooseHealthApp[5538:1534233] 5.20.0 - [Firebase/InstanceID][I-IID023000] Info is not found in Keychain. OSStatus: -25300. Keychain query: {
    acct = "io.chooseHealth.app";
    class = genp;
    gena = "com.google.iid";
    "m_Limit" = "m_LimitAll";
    "r_Attributes" = 1;
    "r_Data" = 1;
    svce = "com.google.iid.checkin";
}
2019-05-03 15:55:24.945697-0500 ChooseHealthApp[5538:1534233] 5.20.0 - [Firebase/InstanceID][I-IID023000] Info is not found in Keychain. OSStatus: -25300. Keychain query: {
    atag = <636f6d2e 676f6f67 6c652e69 69642d7c 4b7c>;
    class = keys;
    "r_Ref" = 1;
    type = 42;
}
2019-05-03 15:55:24.945894-0500 ChooseHealthApp[5538:1534233] 5.20.0 - [Firebase/InstanceID][I-IID023000] Info is not found in Keychain. OSStatus: -25300. Keychain query: {
    atag = <636f6d2e 676f6f67 6c652e69 69642d7c 507c>;
    class = keys;
    "r_Ref" = 1;
    type = 42;
}
2019-05-03 15:55:24.945984-0500 ChooseHealthApp[5538:1534233] 5.20.0 - [Firebase/InstanceID][I-IID009000] No keypair info is found with tag com.google.iid-|K|

Would anyone mind explaining to me what's going on? Why does it want a key pair from my keychain? Was I supposed to add one?

@charlotteliang
Copy link
Contributor

@SephReed This is just info log showing you don't have legacy keychain. This is not related to this bug.

@SephReed
Copy link

SephReed commented May 4, 2019

Thank you.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.