snowplow / snowplow-ios-tracker

Snowplow event tracker for Swift and Objective-C. Add analytics to your iOS, macOS, tvOS and watchOS apps and games
http://snowplow.io
Apache License 2.0
81 stars 93 forks source link

iOS 15 - CFReadStreamGetStatus crash #639

Closed okalentiev closed 3 years ago

okalentiev commented 3 years ago

Describe the bug We noticed a spike in crashes involving CFReadStreamGetStatus. We narrowed it down to Snowplow's TrackerController.track method. The crash log is a bit scrambled, so if there is a better way to debug, please let me know.

I can reproduce this issue 100% of the time using XCode 13 RC.

To Reproduce This is the snippet of the tracking code.

let spEvent = Structured(category: "Interaction", action: "Click")
let data = ["clickedItem": event]
let encoder = JSONEncoder()
if let jsonData = try? encoder.encode(data) {
    if let jsonString = String(data: jsonData, encoding: .utf8) {
        spEvent.property = jsonString
    }
}
tracker?.track(spEvent)

Device information (please complete the following information):

Additional context Crash log: Snowplow.crash.zip

AlexBenny commented 3 years ago

Hi @okalentiev , thanks for reporting the issue. We are investigating on it. I'll keep you in the loop.

okalentiev commented 3 years ago

@AlexBenny Thank you for your swift reply!

I've been running a few tests in the meantime and noticed that it does happen on a fresh install. Once the user logged in to the app, events are being sent without issues. We set the Subject when creating the tracker and set userId to UIDevice.current.identifierForVendor?.uuidString.lowercased() before user is logged in. After login, we set it to the internal user id.

Sounds like it could be related.

AlexBenny commented 3 years ago

@okalentiev thanks for the update!

I'm running our demo app on Xcode 13 RC and iOS 15 simulator. It seems to work fine. Unfortunately, the crash reporting doesn't say much about the real source of the problem.

I would ask you some questions to narrow down the problem:

Sorry for coming back with more questions, but I want to make sure I can track this down with as much info as possible.

okalentiev commented 3 years ago

@AlexBenny

Can you post here your tracker configuration?

Here is our configuration:

let userRegionGlobalContext = GlobalContext(generator: { event in
    return [
        SelfDescribingJson(schema: event.schema ?? "schema", andData: [
            "userRegion": URLRequestSerialization.userRegion // "US" or "EU"
        ] as NSObject)
    ]
})

let networkConfig = NetworkConfiguration(endpoint: "endpoint",
                                         method: .post)

let trackerConfig = TrackerConfiguration()
    .base64Encoding(false)
    .appId("ios")
    .screenViewAutotracking(true)
    .sessionContext(true)
    .screenContext(true)
    .exceptionAutotracking(false)

let emitterConfig = EmitterConfiguration()
    .emitRange(500)
    .threadPoolSize(20)
    .byteLimitPost(52000)
    .requestCallback(self)

tracker = Snowplow.createTracker(
    namespace: "namespace",
    network: networkConfig,
    configurations: [trackerConfig, emitterConfig])

tracker?.globalContexts.add(tag: "userRegion", contextGenerator: userRegionGlobalContext)

I removed the endpoint, schema, and namespace. I can send you them in private if required.

Can you disable installAutotracking in the TrackerConfiguration?

I set .installAutotracking(false) on tracker config and still experienced the crash.

Does commenting out tracker?.track(spEvent) fix the problem on fresh installs?

I mentioned initially that commenting out the tracking helps, but I tested again and got a crash. Apologies for the misleading comment. This time a different crash happened: CFReadStreamSetClient. Since it is happening during debug build, I'm struggling to symbolicate the crash log, so here are the screenshots of the stack trace. Hope they are helpful.

Screenshots ![Screenshot 2021-09-15 at 19 19 24](https://user-images.githubusercontent.com/4539292/133479919-adb14338-36e1-4f6e-9146-252d235e089d.png) ![Screenshot 2021-09-15 at 19 19 32](https://user-images.githubusercontent.com/4539292/133479931-00930738-1084-4914-a525-4625fa8bea54.png)

This time I also got this log:

Task <9EF277F0-6F77-45DC-B788-0DC6E65D0D15>.<100> finished with error [-1017] Error Domain=NSURLErrorDomain Code=-1017 "cannot parse response" UserInfo={_kCFStreamErrorCodeKey=-1, _NSURLErrorFailingURLSessionTaskErrorKey=BackgroundDataTask <9EF277F0-6F77-45DC-B788-0DC6E65D0D15>.<100>, _NSURLErrorRelatedURLSessionTaskErrorKey=(
    "BackgroundDataTask <9EF277F0-6F77-45DC-B788-0DC6E65D0D15>.<100>",
    "LocalDataTask <9EF277F0-6F77-45DC-B788-0DC6E65D0D15>.<100>"
), NSLocalizedDescription=cannot parse response, _kCFStreamErrorDomainKey=4, NSErrorFailingURLStringKey=endpoint/com.snowplowanalytics.snowplow/tp2, NSErrorFailingURLKey=endpoint/com.snowplowanalytics.snowplow/tp2

Can you post an example of data on spEvent?

This is example data of spEvent: {"clickedItem":"welcome_presignup"}.

We also have another method that tracks every view that is open and we are using SelfDescribing event for that.

Here is example data of the self describing json that we pass to the event:

{
    data =     {
        "screen_name" = "screen_animation";
    };
    schema = "shema";
}

Do you set the userId in the SubjectConfiguration?

Yes, we set userId in the subject configuration. Here is the snippet: (tracker is TrackerController that we get from createTracker)

if let user = self.user {
    self.tracker?.subject?.userId = user.remoteid
} else if let deviceid = DeviceInfo.deviceUUID { // <- Just a wrapper around `identifierForVendor`
    self.tracker?.subject?.userId = deviceid
}
AlexBenny commented 3 years ago

Thanks a lot for all the details!

I've done few tests without getting any clue. No crashes, leaks or zombies.

However, there are two things that grab my attention.

Log error

You reported this error:

Task <9EF277F0-6F77-45DC-B788-0DC6E65D0D15>.<100> finished with error [-1017] Error Domain=NSURLErrorDomain Code=-1017 "cannot parse response" UserInfo={_kCFStreamErrorCodeKey=-1, _NSURLErrorFailingURLSessionTaskErrorKey=BackgroundDataTask <9EF277F0-6F77-45DC-B788-0DC6E65D0D15>.<100>, _NSURLErrorRelatedURLSessionTaskErrorKey=(
   "BackgroundDataTask <9EF277F0-6F77-45DC-B788-0DC6E65D0D15>.<100>",
   "LocalDataTask <9EF277F0-6F77-45DC-B788-0DC6E65D0D15>.<100>"
), NSLocalizedDescription=cannot parse response, _kCFStreamErrorDomainKey=4, NSErrorFailingURLStringKey=endpoint/com.snowplowanalytics.snowplow/tp2, NSErrorFailingURLKey=endpoint/com.snowplowanalytics.snowplow/tp2

I haven't been able to replicate this. I get always different errors. I see NSErrorFailingURLStringKey is endpoint/com.snowplowanalytics.snowplow/tp2. I guess you replaced the real url with the endpoint placeholder word.

This error seems indicate that the background task of the tracker is not able to parse the response from the server/collector. Maybe the collector returns an invalid response?!

Global Contexts

You set a global context:

let userRegionGlobalContext = GlobalContext(generator: { event in
   return [
       SelfDescribingJson(schema: event.schema ?? "schema", andData: [
           "userRegion": URLRequestSerialization.userRegion // "US" or "EU"
       ] as NSObject)
   ]
})

Does the call URLRequestSerialization.userRegion require time to be executed? Does the crash happen if you replace this call with a plain string? Does the crash happen if you don't add the global context to the tracker?

okalentiev commented 3 years ago

Yes, I replaced our endpoint URL with endpoint.

I debugged the calls and the noticed two types of response:

However, I tried following the same steps while the app is not connected to the internet and didn't notice the crash. So I think that the background task error seems to be related to the crash.

Also, do you have any insight why it could be iOS 15 specific? I tested on the iOS 14 simulator and the response seems to be the same. However, I don't see background task errors on iOS 14.

I also noticed an extra occurrence of the background task failure:

Task <762CB94D-E075-40EA-84D7-FE40BAAC6C39>.<50> finished with error [-997] Error Domain=NSURLErrorDomain Code=-997 "Lost connection to background transfer service" UserInfo={NSErrorFailingURLStringKey=enpoint/com.snowplowanalytics.snowplow/tp2, NSErrorFailingURLKey=enpoint/com.snowplowanalytics.snowplow/tp2, _NSURLErrorRelatedURLSessionTaskErrorKey=(
    "BackgroundDataTask <762CB94D-E075-40EA-84D7-FE40BAAC6C39>.<50>",
    "LocalDataTask <762CB94D-E075-40EA-84D7-FE40BAAC6C39>.<50>"
), _NSURLErrorFailingURLSessionTaskErrorKey=BackgroundDataTask <762CB94D-E075-40EA-84D7-FE40BAAC6C39>.<50>, NSLocalizedDescription=Lost connection to background transfer service}

Does the call URLRequestSerialization.userRegion require time to be executed?

No URLRequestSerialization.userRegion is declared like this static var userRegion = "US"

Does the crash happen if you replace this call with a plain string? Does the crash happen if you don't add the global context to the tracker?

Yes, the crash is still happening on both cases.

okalentiev commented 3 years ago

During release testing, this crash re-appeared even after disabling SnowPlow tracking. So it seems like an issue on our end. I run a few tests and indeed disabling SnowPlow or even removing dependency entirely doesn't resolve the crash. SnowPlow tracking did increase the number of occurrences and reproducibility of the crash though. That's why I got confused.

Thank you so much @AlexBenny for your assistance and for looking into this. Apologies for the false alarm 🙏

AlexBenny commented 3 years ago

Thanks @okalentiev to let us know. I was suspecting this as I haven't been able to reproduce it and I couldn't find what the source of the problem could be. In any case, we would be happy to have any feedback on this issue. It might help us to improve the tracker furthermore avoiding possible interferences with other components of the app.