5

The title reflects what I think is happening, but I haven't been able to prove it beyond a shadow of a doubt. I've added a number of log calls to our sentry instance to try to narrow down what's happening

Background: Our app has a root VC called LoadingViewController which has some logic to determine whether we have a logged in user or not. If we do, it shows the homescreen, if we don't it shows the login/register screen. Intermittently, the login screen is shown when the homescreen should show. Our app uses JWT to authenticate with our backend, but I'm fairly confident token expiry is not the issue; the logging around an expired token forcing a logout is not getting called according to the logs

Research: I've also reviewed these questions/issues and while similar, don't solve what I'm seeing

What I see: The LoadingViewController starting up. Going into bootUser, not getting a User back from the UserDataService, returning false, and then resetting everything. This is why I think that the User object isn't there when it's being queried for.

This usually happens after I haven't used the app for a while, and not all the time. I haven't been able to force the issue by either force-quitting the app or loading up a bunch of games to try to force it out of memory and going back to it.

I'm at a little bit of a loss. Is there anything I haven't thought of or could check?

Thanks

Code

Subset of our LoadingViewController:

class LoadingViewController: UIViewController {
    override func viewDidLoad() {
        breadcrumbs.append("LoadingViewController.viewDidLoad \(UserDataService.getCurrentUser()?.id) \(UserDataService.getCurrentUser()?.token)")
        super.viewDidLoad()

        // determine if we have a user
        if self.bootUser() {
            return
        }

        // If we got hereUser is not logged in. wipe it
        NSOperationQueue().addOperationWithBlock() {
            let realm = KidRealm.realm()
            CacheUtils.purgeRealm(realm)
        }
    }

    func bootUser() -> Bool {
        breadcrumbs.append("LoadingViewController.bootUser 0 \(UserDataService.getCurrentUser()?.id) \(UserDataService.getCurrentUser()?.token)")
        if let user = UserDataService.getCurrentUser(),
            let checkToken = user.token
            where checkToken != "" {
            breadcrumbs.append("LoadingViewController - 1 have user \(UserDataService.getCurrentUser()?.id) \(UserDataService.getCurrentUser()?.token)")
            KA.initUser(currentUser)

            // user is a full user, bring them to the homepage
            if let vc = self.storyboard?.instantiateViewControllerWithIdentifier("betacodeview") as? BetaCodeViewController {
                breadcrumbs.append("LoadingViewController - 3 betacodeview \(UserDataService.getCurrentUser()?.id) \(UserDataService.getCurrentUser()?.token)")
                self.performSegueWithIdentifier("gotohomeview", sender: self)
                return true
            }
            breadcrumbs.append("LoadingViewController - 4 skip? \(UserDataService.getCurrentUser()?.id) \(UserDataService.getCurrentUser()?.token)")
            logLogoutIssues("bootUser with token. !full !vc \(UserDataService.count())")
        }
        breadcrumbs.append("LoadingViewController - 5 no token / user \(UserDataService.getCurrentUser()?.id) \(UserDataService.getCurrentUser()?.token)")
        logLogoutIssues("bootUser with no token. token: (\(token)) \(UserDataService.count())")
        return false
    }

Subset of the User model

class User: Object {
    dynamic var id: Int = -1
    dynamic var UUID = ""
    dynamic var email: String?
    dynamic var firstName: String?
    dynamic var lastName: String?
    dynamic var facebookId: String?
    dynamic var instagramId: String?
    dynamic var photoUrl: String?
    dynamic var token: String?
    dynamic var fullUser = false
    dynamic var donationPercent: Int = 0

    // Extra info

    dynamic var birthday: NSDate?
    dynamic var phone: String?
    dynamic var address1: String?
    dynamic var address2: String?
    dynamic var zip: String?
    dynamic var city: String?
    dynamic var state: String?

    // User settings
    dynamic var allowNotification: Bool = true

    // temporary in memory, not saved
    var profilePhoto = NSData()

    override static func primaryKey() -> String? {
        return "UUID"
    }

    func setUuid(UUID: String) {
        self.UUID = UUID
    }

    func setUuid() {
        self.UUID = SwiftyUUID.UUID().CanonicalString()
    }
}

Subset of the UserDataService which the LoadingViewController uses to get the current user

struct UserDataService: Saveable, Deletable {
    static func getCurrentUser(realm: Realm) -> User? {
        let getUser = realm.objects(User)
        if let user = getUser.first {
            return user
        }

        return nil
    }

    static func getCurrentUser() -> User? {
        let realm = KidRealm.realm()
        return UserDataService.getCurrentUser(realm)
    }
}

Subset of CacheUtils, used to clear the realm for the user to login or register (also called during logout)

struct CacheUtils {
    static func purgeRealm(realm: Realm) {
        try! realm.write {
            realm.deleteAll()
        }
    }
}

Lastly, KidRealm, which sets up the encryption. This is used both in the main app, and a background process when push notifications come in

struct KidRealm {
    static func realm() -> Realm {
        let key = getKey()
        let configuration = Realm.Configuration(encryptionKey: key)
        let realm = try! Realm(configuration: configuration)

        return realm
    }

    static func getKeyString(key: NSData) -> String {
        return "\(key)".stringByTrimmingCharactersInSet(NSCharacterSet(charactersInString: "<>")).stringByReplacingOccurrencesOfString(" ", withString: "")
    }

    static func getKey() -> NSData {
        // Identifier for our keychain entry - should be unique for your application
        let keychainIdentifier = "com.kidfund.kidfund1.keychain"
        let keychainIdentifierData = keychainIdentifier.dataUsingEncoding(NSUTF8StringEncoding, allowLossyConversion: false)!

        // First check in the keychain for an existing key
        var query: [NSString: AnyObject] = [
            kSecClass: kSecClassKey,
            kSecAttrApplicationTag: keychainIdentifierData,
            kSecAttrKeySizeInBits: 512,
            kSecReturnData: true,
            kSecAttrAccessible: kSecAttrAccessibleAfterFirstUnlock
        ]

        // To avoid Swift optimization bug, should use withUnsafeMutablePointer() function to retrieve the keychain item
        // See also: https://stackoverflow.com/questions/24145838/querying-ios-keychain-using-swift/27721328#27721328
        var dataTypeRef: AnyObject?
        var status = withUnsafeMutablePointer(&dataTypeRef) { SecItemCopyMatching(query, UnsafeMutablePointer($0)) }
        if status == errSecSuccess {
            return dataTypeRef as! NSData
        }

        // No pre-existing key from this application, so generate a new one
        let keyData = NSMutableData(length: 64)!
        let result = SecRandomCopyBytes(kSecRandomDefault, 64, UnsafeMutablePointer<UInt8>(keyData.mutableBytes))
        assert(result == 0, "Failed to get random bytes")

        // Store the key in the keychain
        query = [
            kSecClass: kSecClassKey,
            kSecAttrApplicationTag: keychainIdentifierData,
            kSecAttrKeySizeInBits: 512,
            kSecValueData: keyData,
            kSecAttrAccessible: kSecAttrAccessibleAfterFirstUnlock
        ]

        status = SecItemAdd(query, nil)
        assert(status == errSecSuccess, "Failed to insert the new key in the keychain")

        return keyData
    }
}

Update 1:

I also have a global currentUser helper, which wraps calls to my UserDataService. I don't think this is an issue, but adding for completeness. This exists for legacy reasons and is on the list to be refactored out at some point.

var currentUser: User {
    get {
        if let user = UserDataService.getCurrentUser() {
            return user
        }

        breadcrumbs.append("Getting empty currentUser \(UserDataService.count())")
        logLogoutIssues("Getting empty currentUser \(UserDataService.count())")
        return User()
    }
}

Update 2:

Based on the thread that Peba pointed me to, I'm pushing some fixes now that include:

  • extra logging around the keychain activity
  • a sleep(1) retry if it doesn't get the key on the first try
  • same for the write
  • cache the key in memory so I don't hit the keychain as much (not thrilled about this but it is what it is)
  • adding the Keychain Sharing
Community
  • 1
  • 1
timbroder
  • 858
  • 1
  • 13
  • 25
  • I had a similar issue which was cause by the iOS Security framework. It happened when calling the functions SecItemCopyMatching and SecItemAdd. Gladly it only occurred while debugging the app on a device. See [this](http://stackoverflow.com/questions/20344255/secitemadd-and-secitemcopymatching-returns-error-code-34018-errsecmissingentit) – Peba Nov 28 '16 at 16:17
  • @Peba thanks reading through that now. Was that a crashing issue for you or silently failing? – timbroder Nov 28 '16 at 16:29
  • Since I interfaced the function calls with the KeychainAccess framework, the framework itself threw an error printing error code -34018 and crashed the app afterwards. I'm pretty sure the way it is handled in `func getKey()` it is going to fail silently. Try adding an else clause in `status == errSecSuccess` to check for possible failures. – Peba Nov 28 '16 at 16:38
  • @Peba This is interesting. After reading that thread I'm wondering if because the check for the key is silently failing, and we're creating a new key (and overwriting the old key in the keychain) , and instantiating realm from that, we may be accidentally creating multiple realms. The "logged out" is really "fresh new Realm". Will add some more logging and let you know. If it is this would love to give you credit. Thanks – timbroder Nov 28 '16 at 18:20
  • nm, SecItemAdd will fail if that happens – timbroder Nov 28 '16 at 18:50
  • SecItemAdd may also fail silently. While unlikely to happen when debugging, assertions are only guaranteed to run if the Swift Compiler Optimization Level is set to -Onone. You may find the optimization level at `Build Settings>Swift Compiler - Code Generation>Optimization Level` – Peba Nov 28 '16 at 19:49
  • Got it, thanks I didn't know that. I'm pushing some fixes now that include extra logging around the keychain activity, a sleep(1) retry if it doesn't get the key on the first try, same for the write, cache the key in memory so I don't hit the keychain as much (not thrilled about this but it is what it is), adding the Keychain Sharing – timbroder Nov 28 '16 at 21:14
  • It's really difficult to figure it out what's wrong here because there are a lot of extra code. You can try do debug it by setting breakpoints to methods where you remove data from realm or where you get an invalid user. – Dmitry Nov 29 '16 at 13:06
  • Agree with Dmitry here, it's difficult to give advice with the current state of your report. If you can share clear repro steps or a sample project, others might be able to help figure what you're trying to do and why it's not working. – jpsim Dec 05 '16 at 18:40
  • Hey @timbroder, I have a similar issue. The user is very often logged out between app launches. I don't know where it comes from but the realm database is empty. Any idea? – Marie Dm Apr 26 '17 at 15:13
  • @MarieDm still struggling with this unfortunatly – timbroder Apr 26 '17 at 15:28
  • @timbroder hey there! I'm curious, reading through your issue. Did you eventually find the issue and a fix? I haven't had this issue, but just in case, I'm inquiring :) – Bptstmlgt Nov 13 '17 at 17:39
  • 1
    @Bptstmlgt no specific fix unfortunately :( We better handle when it happens in our UI now but it still pops up from time to time – timbroder Nov 13 '17 at 18:28
  • Did you ever find a solution to this? I'm seeing the same behaviour with very similar setup and it's driving me insane trying to figure out what's going on :) – SveinnV Mar 04 '19 at 15:50
  • @SveinnV unfortunately, no – timbroder Mar 05 '19 at 16:47

0 Answers0