feat: add logging for testing background queue

CHANGELOG.md

@@ -1,3 +1,24 @@
+# [1.0.0-alpha.19](https://github.com/customerio/customerio-ios/compare/1.0.0-alpha.18...1.0.0-alpha.19) (2021-12-03)
+
+
+### Bug Fixes
+
+* logs now show up in mac console app ([#80](https://github.com/customerio/customerio-ios/issues/80)) ([535d0be](https://github.com/customerio/customerio-ios/commit/535d0be1bdbd3a43d9ba1fe2fabeb4002ea5d35f))
+
+# [1.0.0-alpha.18](https://github.com/customerio/customerio-ios/compare/1.0.0-alpha.17...1.0.0-alpha.18) (2021-11-18)
+
+
+### Bug Fixes
+
+* deep links previously being ignored ([#79](https://github.com/customerio/customerio-ios/issues/79)) ([2041767](https://github.com/customerio/customerio-ios/commit/204176735a8641a77d58232af1daa4e290ee0ca4))
+
+# [1.0.0-alpha.17](https://github.com/customerio/customerio-ios/compare/1.0.0-alpha.16...1.0.0-alpha.17) (2021-11-03)
+
+
+### Bug Fixes
+
+* improve user-agent with more detail ([#74](https://github.com/customerio/customerio-ios/issues/74)) ([4301034](https://github.com/customerio/customerio-ios/commit/43010347680d84dfa7d2b782bce18a25b40b8296))
+
 # [1.0.0-alpha.16](https://github.com/customerio/customerio-ios/compare/1.0.0-alpha.15...1.0.0-alpha.16) (2021-10-08)
 
 

Sources/MessagingPush/MessagingPush+NotificationCenter.swift

@@ -45,10 +45,9 @@ public extension MessagingPush {
             return false
         }
 
-        switch response.actionIdentifier {
-        case UNNotificationDismissActionIdentifier, UNNotificationDefaultActionIdentifier:
-            cleanup(pushContent: pushContent)
+        cleanup(pushContent: pushContent)
 
+        switch response.actionIdentifier {
         case UNNotificationDefaultActionIdentifier: // push notification was touched.
             if let deepLinkurl = pushContent.deepLink {
                 UIApplication.shared.open(url: deepLinkurl)

Sources/MessagingPush/MessagingPush.swift

@@ -33,7 +33,9 @@ public class MessagingPush: MessagingPushInstance {
         // XXX: customers may want to know if siteId nil. Log it to them to help debug.
         if let siteId = customerIO.siteId {
             let diGraphTracking = DITracking.getInstance(siteId: siteId)
+            let logger = diGraphTracking.logger
 
+            logger.info("MessagingPush module setup with SDK")
             // Register MessagingPush module hooks now that the module is being initialized.
             let hooks = diGraphTracking.hooksManager
             let moduleHookProvider = MessagingPushModuleHookProvider(siteId: siteId)

Sources/MessagingPush/MessagingPushImplementation.swift

@@ -5,16 +5,19 @@ internal class MessagingPushImplementation: MessagingPushInstance {
     private let profileStore: ProfileStore
     private let backgroundQueue: Queue
     private var globalDataStore: GlobalDataStore
+    private let logger: Logger
 
     /// testing init
     internal init(
         profileStore: ProfileStore,
         backgroundQueue: Queue,
-        globalDataStore: GlobalDataStore
+        globalDataStore: GlobalDataStore,
+        logger: Logger
     ) {
         self.profileStore = profileStore
         self.backgroundQueue = backgroundQueue
         self.globalDataStore = globalDataStore
+        self.logger = logger
     }
 
     init(siteId: String) {
@@ -24,18 +27,23 @@ internal class MessagingPushImplementation: MessagingPushInstance {
         self.profileStore = diGraph.profileStore
         self.backgroundQueue = diGraph.queue
         self.globalDataStore = diGraph.globalDataStore
+        self.logger = diGraph.logger
     }
 
     /**
      Register a new device token with Customer.io, associated with the current active customer. If there
      is no active customer, this will fail to register the device
      */
     public func registerDeviceToken(_ deviceToken: String) {
+        logger.info("registering device token \(deviceToken)")
+
+        logger.debug("storing device token to device storage \(deviceToken)")
         // no matter what, save the device token for use later. if a customer is identified later,
         // we can reference the token and register it to a new profile.
         globalDataStore.pushDeviceToken = deviceToken
 
         guard let identifier = profileStore.identifier else {
+            logger.info("no profile identified so not registering device token a profile")
             return
         }
 
@@ -49,12 +57,17 @@ internal class MessagingPushImplementation: MessagingPushInstance {
      Delete the currently registered device token
      */
     public func deleteDeviceToken() {
+        logger.info("deleting device token request made")
+
         guard let existingDeviceToken = globalDataStore.pushDeviceToken else {
+            logger.info("no device token exists so ignoring request to delete")
             return // no device token to delete, ignore request
         }
-        globalDataStore.pushDeviceToken = nil
+        // Do not delete push token from device storage. The token is valid
+        // once given to SDK. We need it for future profile identifications.
 
         guard let identifiedProfileId = profileStore.identifier else {
+            logger.info("no profile identified so not removing device token from profile")
             return // no profile to delete token from, ignore request
         }
 
@@ -71,6 +84,10 @@ internal class MessagingPushImplementation: MessagingPushInstance {
         event: Metric,
         deviceToken: String
     ) {
+        logger.info("push metric \(event.rawValue)")
+
+        logger.debug("delivery id \(deliveryID) device token \(deviceToken)")
+
         _ = backgroundQueue.addTask(type: QueueTaskType.trackPushMetric.rawValue,
                                     data: MetricRequest(deliveryID: deliveryID, event: event, deviceToken: deviceToken,
                                                         timestamp: Date()))
@@ -82,21 +99,28 @@ extension MessagingPushImplementation: ProfileIdentifyHook {
     // privacy and messaging releveance reasons. We only want to send messages to the currently
     // identified profile.
     func beforeIdentifiedProfileChange(oldIdentifier: String, newIdentifier: String) {
+        logger.debug("hook: deleting device before identifying new profile")
+
         deleteDeviceToken()
     }
 
     // When a profile is identified, try to automatically register a device token to them if there is one assigned
     // to this device
     func profileIdentified(identifier: String) {
         guard let existingDeviceToken = globalDataStore.pushDeviceToken else {
+            logger.debug("hook: no push token stored so not automatically registering token to profile")
             return
         }
 
+        logger.debug("hook: automatically registering token to profile identified. token: \(existingDeviceToken)")
+
         registerDeviceToken(existingDeviceToken)
     }
 
     // stop sending push to a profile that is no longer identified
     func profileStoppedBeingIdentified(oldIdentifier: String) {
+        logger.debug("hook: deleting device token from profile no longer identified")
+
         deleteDeviceToken()
     }
 }

Sources/MessagingPushFCM/MessagingPush+FCM.swift

@@ -19,8 +19,8 @@ public protocol MessagingPushFCMInstance: AutoMockable {
 /**
  MessagingPush extension to support FCM push notification messaging.
   */
-public extension MessagingPush {
-    func messaging(
+extension MessagingPush: MessagingPushFCMInstance {
+    public func messaging(
         _ messaging: Any,
         didReceiveRegistrationToken fcmToken: String?
     ) {
@@ -30,7 +30,7 @@ public extension MessagingPush {
         registerDeviceToken(deviceToken)
     }
 
-    func application(
+    public func application(
         _ application: Any,
         didFailToRegisterForRemoteNotificationsWithError error: Error
     ) {

Sources/Tracking/Background Queue/Queue.swift

@@ -64,38 +64,46 @@ public class CioQueue: Queue {
     }
 
     public func addTask<T: Codable>(type: String, data: T) -> (success: Bool, queueStatus: QueueStatus) {
+        logger.info("adding queue task \(type)")
+
         guard let data = jsonAdapter.toJson(data, encoder: nil) else {
+            logger.error("fail adding queue task, json encoding fail.")
+
             return (success: false,
                     queueStatus: QueueStatus(queueId: siteId, numTasksInQueue: storage.getInventory().count))
         }
 
+        logger.debug("added queue task data \(data.string ?? "")")
+
         let addTaskResult = storage.create(type: type, data: data)
         processQueueStatus(addTaskResult.queueStatus)
 
         return addTaskResult
     }
 
     public func run(onComplete: @escaping () -> Void) {
-        logger.verbose("Manually running background queue")
+        logger.info("manually running background queue")
 
         runRequest.start(onComplete: onComplete)
     }
 
     private func processQueueStatus(_ status: QueueStatus) {
-        logger.verbose("Processing queue status \(status).")
+        logger.debug("processing queue status \(status).")
         let isManyTasksInQueue = status.numTasksInQueue >= sdkConfigStore.config.backgroundQueueMinNumberOfTasks
 
         let runQueue = isManyTasksInQueue
 
         if runQueue {
-            logger.verbose("Automatically running background queue")
+            logger.info("automatically running background queue")
 
             // not using [weak self] to assert that the queue will complete and callback once started.
             // this might keep this class in memory and not get garbage collected once customer is done using it
             // but it will get released once the queue is done running.
             runRequest.start {
-                self.logger.verbose("Automatic running background queue completed")
+                self.logger.info("automatic running background queue completed")
             }
+        } else {
+            logger.debug("queue skip running automatically")
         }
     }
 }

Sources/Tracking/Background Queue/QueueRunRequest.swift

@@ -12,6 +12,8 @@ public class CioQueueRunRequest: QueueRunRequest {
     private let requestManager: QueueRequestManager
     private let logger: Logger
 
+    private let shortTaskId: (String) -> String = { $0[0 ..< 5] }
+
     init(runner: QueueRunner, storage: QueueStorage, requestManger: QueueRequestManager, logger: Logger) {
         self.runner = runner
         self.storage = storage
@@ -30,40 +32,35 @@ public class CioQueueRunRequest: QueueRunRequest {
     private func startNewRequestRun() {
         let inventory = storage.getInventory()
 
-        runTasks(query: inventory)
+        runTasks(query: inventory, queryTotalNumberTasks: inventory.count)
     }
 
-    private func runTasks(query: [QueueTaskMetadata]) {
-        let goToNextTask: () -> Void = {
-            var newQuery = query
-            newQuery.removeFirst()
-            self.runTasks(query: newQuery)
-        }
-
+    private func runTasks(query: [QueueTaskMetadata], queryTotalNumberTasks: Int) {
         if query.isEmpty { // we hit the end of the current inventory. Done!
-            logger.verbose("background queue out of tasks.")
-
+            logger.debug("queue out of tasks to run.")
             requestManager.requestComplete()
-
             return
         }
 
         let nextTaskToRunInventoryItem = query[0]
         let nextTaskStorageId = nextTaskToRunInventoryItem.taskPersistedId
         guard let nextTaskToRun = storage.get(storageId: nextTaskStorageId) else {
-            // delete task from inventory since we can't find it in storage so we don't want to run it.
-            // ignore result because if it's successful or not, all we can do is try and delete and move on.
-            _ = storage.delete(storageId: nextTaskStorageId)
-
             // log error. this scenario shouldn't happen where task can't be found.
             logger.error("Tried to get queue task with storage id: \(nextTaskStorageId), but storage couldn't find it.")
 
-            return goToNextTask()
+            // delete task from inventory since we can't find it in storage so we don't want to run it.
+            // ignore result because if it's successful or not, all we can do is try and delete and move on.
+            let success = storage.delete(storageId: nextTaskStorageId)
+            logger.debug("deleted task \(nextTaskStorageId) success: \(success)")
+
+            return goToNextTask(query: query, queryTotalNumberTasks: queryTotalNumberTasks)
         }
 
-        logger
-            .verbose("background queue next task \(nextTaskStorageId). query tasks remaining: \(query.count)")
-        logger.debug("next background queue task to run: \(nextTaskToRunInventoryItem) => \(nextTaskToRun)")
+        logger.debug("queue tasks left to run: \(query.count) out of \(queryTotalNumberTasks)")
+        logger.debug("""
+        queue next task to run: \(shortTaskId(nextTaskStorageId)),
+        \(nextTaskToRun.type), \(nextTaskToRun.data.string ?? ""), \(nextTaskToRun.runResults)
+        """)
 
         // we are not using [weak self] because if the task is currently running,
         // we dont want the result handler to get garbage collected which could
@@ -74,21 +71,36 @@ public class CioQueueRunRequest: QueueRunRequest {
         runner.runTask(nextTaskToRun) { result in
             switch result {
             case .success:
-                self.logger.verbose("background queue task \(nextTaskStorageId) success")
+                self.logger.debug("queue task \(self.shortTaskId(nextTaskStorageId)) ran successfully")
 
-                _ = self.storage.delete(storageId: nextTaskToRunInventoryItem.taskPersistedId)
+                self.logger.debug("queue deleting task \(self.shortTaskId(nextTaskStorageId))")
+                let success = self.storage.delete(storageId: nextTaskToRunInventoryItem.taskPersistedId)
+                self.logger.debug("queue deleting task \(self.shortTaskId(nextTaskStorageId)) success: \(success)")
             case .failure(let error):
-                self.logger.verbose("background queue task \(nextTaskStorageId) fail - \(error.localizedDescription)")
+                self.logger
+                    .debug("queue task \(self.shortTaskId(nextTaskStorageId)) fail - \(error.localizedDescription)")
 
                 let executedTaskPreviousRunResults = nextTaskToRun.runResults
                 let newRunResults = executedTaskPreviousRunResults
                     .totalRunsSet(executedTaskPreviousRunResults.totalRuns + 1)
 
-                _ = self.storage.update(storageId: nextTaskToRunInventoryItem.taskPersistedId,
-                                        runResults: newRunResults)
+                self.logger.debug("""
+                queue task \(self.shortTaskId(nextTaskStorageId)) updating run history
+                from: \(nextTaskToRun.runResults) to: \(newRunResults)
+                """)
+
+                let success = self.storage.update(storageId: nextTaskToRunInventoryItem.taskPersistedId,
+                                                  runResults: newRunResults)
+                self.logger.debug("queue task \(self.shortTaskId(nextTaskStorageId)) update success \(success)")
             }
 
-            return goToNextTask()
+            return self.goToNextTask(query: query, queryTotalNumberTasks: queryTotalNumberTasks)
         }
     }
+
+    private func goToNextTask(query: [QueueTaskMetadata], queryTotalNumberTasks: Int) {
+        var newQuery = query
+        newQuery.removeFirst()
+        runTasks(query: newQuery, queryTotalNumberTasks: queryTotalNumberTasks)
+    }
 }

Sources/Tracking/Background Queue/QueueRunner.swift

@@ -39,7 +39,7 @@ public class CioQueueRunner: ApiSyncQueueRunner, QueueRunner {
             }
 
             if !hookHandled {
-                let errorMessage = "Task \(task.type) not handled by anything including hooks"
+                let errorMessage = "task \(task.type) not handled by any module"
                 onComplete(.failure(.internalError(message: errorMessage)))
             }
         }

Sources/Tracking/CustomerIO.swift

@@ -75,6 +75,12 @@ public class CustomerIO: CustomerIOInstance {
 
     internal var globalData: GlobalDataStore = CioGlobalDataStore()
 
+    private var logger: Logger? {
+        guard let siteId = self.siteId else { return nil }
+
+        return DITracking.getInstance(siteId: siteId).logger
+    }
+
     /**
      Constructor for singleton, only.
 
@@ -84,10 +90,15 @@ public class CustomerIO: CustomerIOInstance {
         if let siteId = globalData.sharedInstanceSiteId {
             let diGraph = DITracking.getInstance(siteId: siteId)
             let credentialsStore = diGraph.sdkCredentialsStore
+            let logger = diGraph.logger
 
             // if credentials are not available, we should not set implementation
             if credentialsStore.load() != nil {
+                logger.info("shared instance of Customer.io loaded and ready to use")
+
                 self.implementation = CustomerIOImplementation(siteId: siteId)
+            } else {
+                logger.info("shared instance of Customer.io needs to be initialized before ready to use")
             }
         }
     }
@@ -122,6 +133,8 @@ public class CustomerIO: CustomerIOInstance {
         Self.shared.setCredentials(siteId: siteId, apiKey: apiKey, region: region)
 
         Self.shared.implementation = CustomerIOImplementation(siteId: siteId)
+
+        Self.shared.logger?.info("shared Customer.io SDK instance initialized and ready to use for site id: \(siteId)")
     }
 
     /**