Crashes and Non-Fatals are not getting logged

ghost commented 4 years ago

[REQUIRED] Step 1: Describe your environment

Xcode version: 11.6 (11E708)
Firebase SDK version: 6.31.0
Firebase Component: Crashlytics
Component version: 4.5.0
Installation method: Carthage

[REQUIRED] Step 2: Describe the problem

The crashes and non-fatals are not getting logged in the firebase console. The crash is produced using fatalError() The non-fatals are logged using func record(error: Error)

Here are the logs:

2020-09-04 15:55:43.829580+0200 TrainerApp[82721:16463822] [Firebase/Crashlytics] Version 4.5.0 2020-09-04 15:55:43.870513+0200 TrainerApp[82721:16464299] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics] Running on iOS Simulator (iPad), 13.6.0 (19F101) 2020-09-04 15:55:43.871091+0200 TrainerApp[82721:16464299] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] Automatic data collection is enabled. 2020-09-04 15:55:43.871226+0200 TrainerApp[82721:16464299] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] Unsent reports will be uploaded at startup 2020-09-04 15:55:44.069940+0200 TrainerApp[82721:16464302] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-04 15:55:44.070124+0200 TrainerApp[82721:16464302] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-04 15:55:44.070236+0200 TrainerApp[82721:16464302] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report

Note: The log in the debugger does not confirm whether the submission of the report is a success or a failure. Tried it both on the device and simulator.

In the dashboard, there is no missing dsyms, for the version I am crashing the app.

ghost commented 4 years ago

More logs:

2020-09-07 11:08:26.236183+0200 TrainerApp[23050:18047292] [Firebase/Crashlytics] Version 4.5.0 2020-09-07 11:08:26.236506+0200 TrainerApp[23050:18047682] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics] Running on iOS Simulator (iPad), 13.6.0 (19F101) 2020-09-07 11:08:26.243392+0200 TrainerApp[23050:18047682] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] Automatic data collection is enabled. 2020-09-07 11:08:26.243520+0200 TrainerApp[23050:18047682] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] Unsent reports will be uploaded at startup 2020-09-07 11:08:26.282372+0200 TrainerApp[23050:18047682] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] Preparing the report for the new endpoint: 1 2020-09-07 11:08:26.282666+0200 TrainerApp[23050:18047691] [Firebase/Crashlytics] Packaged report with id 'b5a64b57121d499e8b4eeb16289d5493' for submission 2020-09-07 11:08:26.282941+0200 TrainerApp[23050:18047682] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-07 11:08:26.444275+0200 TrainerApp[23050:18047678] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-07 11:08:26.447400+0200 TrainerApp[23050:18047691] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-07 11:08:26.481444+0200 TrainerApp[23050:18047691] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-07 11:08:26.481574+0200 TrainerApp[23050:18047691] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-07 11:08:26.481704+0200 TrainerApp[23050:18047691] 6.31.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report

It looks like there is a new endpoint. Could that be an issue?

ghost commented 4 years ago

This binary seems to be working: binary "https://dl.google.com/dl/firebase/ios/carthage/FirebaseCrashlyticsBinary.json" == 6.27.0

Crashlytics version: 4.2.0

ghost commented 4 years ago

Updated the Crashlytics binary to test if the problem is resolved in the new version, but the problem remains:

2020-09-14 11:30:57.064370+0200 TrainerApp[12004:172243] [Firebase/Crashlytics] Version 4.6.0 2020-09-14 11:30:57.064949+0200 TrainerApp[12004:172600] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics] Running on iOS Simulator (iPad), 13.7.0 (19G2021) 2020-09-14 11:30:57.071109+0200 TrainerApp[12004:172584] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] Automatic data collection is enabled. 2020-09-14 11:30:57.071262+0200 TrainerApp[12004:172584] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] Unsent reports will be uploaded at startup 2020-09-14 11:30:57.131076+0200 TrainerApp[12004:172585] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] Preparing the report for the new endpoint: 1 2020-09-14 11:30:57.131409+0200 TrainerApp[12004:172584] [Firebase/Crashlytics] Packaged report with id '059add6f5fa94dcda4753541cafa9ab0' for submission 2020-09-14 11:30:57.131606+0200 TrainerApp[12004:172585] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report

morganchen12 commented 4 years ago

Hey @puneet-egym, the new endpoint log you've called out has been in the code for about 6 months now, before the release of 6.27. It's unlikely to be caused by that change.

The only significant change between 6.27 and 6.28 was #5904.

samedson commented 4 years ago

@puneet-egym could you reach out to Firebase Support? We would like to dig deeper and are hoping you can share more information with us.

ghost commented 4 years ago

Thanks @samedson. I have opened a support ticket. Let me know if you need more information.

glaures-ioki commented 4 years ago

We are having exactly the same issue:

2020-09-21 18:23:34.202522+0200 Barnim[15720:3551606] [Firebase/Crashlytics] Version 4.6.0 2020-09-21 18:23:34.205482+0200 Barnim[15720:3551766] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics] Running on iPhone10,6, 13.7.0 (17H35) 2020-09-21 18:23:34.238060+0200 Barnim[15720:3551774] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports:Event] Registered Firebase Analytics event listener 2020-09-21 18:23:34.238386+0200 Barnim[15720:3551774] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] Automatic data collection is enabled. 2020-09-21 18:23:34.254841+0200 Barnim[15720:3551774] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] Unsent reports will be uploaded at startup 2020-09-21 18:23:34.422067+0200 Barnim[15720:3551774] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] Preparing the report for the new endpoint: 1 2020-09-21 18:23:34.423129+0200 Barnim[15720:3551772] [Firebase/Crashlytics] Packaged report with id '3901084235a04cdf980d96b4a53e3e90' for submission 2020-09-21 18:23:34.423521+0200 Barnim[15720:3551774] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-21 18:23:34.428194+0200 Barnim[15720:3551764] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports:Event] Sending event. 2020-09-21 18:23:34.642033+0200 Barnim[15720:3551766] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-21 18:23:34.644643+0200 Barnim[15720:3551773] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-21 18:23:34.659053+0200 Barnim[15720:3551764] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-21 18:23:34.659324+0200 Barnim[15720:3551764] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-21 18:23:34.659404+0200 Barnim[15720:3551764] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-21 18:23:34.661328+0200 Barnim[15720:3551764] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-21 18:23:34.661492+0200 Barnim[15720:3551764] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-21 18:23:34.661660+0200 Barnim[15720:3551764] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-21 18:23:34.661769+0200 Barnim[15720:3551764] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-21 18:23:34.663458+0200 Barnim[15720:3551764] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report 2020-09-21 18:23:34.665503+0200 Barnim[15720:3551764] 6.32.0 - [Firebase/Crashlytics][I-CLS000000] [Crashlytics:Crash:Reports] Submitting report

And the Firebase dashboard is empty:

samedson commented 4 years ago

@glaures-ioki could you try enabling GDT debug logging and posting the logs again? You can go here: GDTCORConsoleLogger.m#L19 and set the value to GDTCORLoggingLevelDebug

glaures-ioki commented 4 years ago

@samedson I deleted the unrelated Firebase logs (Performance, Analytics...) and left all the rest. Hope it can help. FirebaseCrashlyticsIssue.log

maksymmalyhin commented 4 years ago

@glaures-ioki Thank you for posting the logs. From the logs I can see the events where accepted by GoogleDataTransport. I would expect to see more logs from [GoogleDataTransport] attributed to the saving the event to the storage and uploading them. I wonder if you can see more GoogleDataTransport logs? If yes, could you send them as well please? If no, we will need to find out why. Is the application crashing after that? If not, another reason may be a deadlock somewhere in Crashlytics/GoogleDataTransport code. Could you try to pause execution of the app under the debugger and post call stack of the threads.

glaures-ioki commented 4 years ago

@maksymmalyhin

I wonder if you can see more GoogleDataTransport logs?

Just to be sure, I made an other one. This time I am absolutely certain that all GoogleDataTransport and Firebase/Crashlytics related logs are here. To have the maximum amount of logs I used GDTCORLoggingLevel.debug (it was already the case in the first logs). I also read your PR here so I moved the line before FirebaseApp.configure().

FirebaseCrashlyticsIssue2.log

Is the application crashing after that?

No, the app is open in foreground, screen on, doing nothing

Could you try to pause execution of the app under the debugger and post call stack of the threads.

You mean while it's standing doing nothing ? Not sure if there is anything to see. Tell me if you want me to do it at an other time.

maksymmalyhin commented 4 years ago

@glaures-ioki yeah, that's exactly what I was asking, thank you for the provided info. I can see pending blocks in the clearcut and auth queues but the related threads are not shown. Could you please make sure you have all filters cleared in the debug navigator to see all the details:

glaures-ioki commented 4 years ago

@maksymmalyhin There you go, hope it can help 🙂

maksymmalyhin commented 4 years ago

@glaures-ioki Thank you, it helps. Not too much but helps 😄. I expected to see a thread waiting on a lock or something like this. The logs don't look exactly right, we will keep investigating what may be wrong here.

glaures-ioki commented 4 years ago

Yeah, I expected to see a little bit more stuff too. Anyway, let me know if you need more info 😉

ghost commented 4 years ago

@maksymmalyhin I noticed something weird in my simulator logs. If I have crash logs accumulated using Crashlytics version 4.2.0 and then update crashlytics to 4.6.1 and open the simulator with updated build, the report submission was successful.

maksymmalyhin commented 4 years ago

@puneet-egym There have been several bug fixes in GoogleDataTransport SDK (which is used to upload the crash data) released since Crashlytics 4.2.0 release. Potentially you experienced one of the issues that now are fixed. We would recommend to use the most recent versions of Firebase SDKs when possible.

maksymmalyhin commented 4 years ago

@glaures-ioki I can see a couple options to explain the provided logs:

The Crashlytics events are lost somewhere here (e.g. because storage == nil there)
Log function is not working properly so we cannot see the full picture

Both options look pretty weird to me.

I cannot reproduce the issue locally. Will it be possible to provide a project where the issue is reproducible? If the project contains something you wouldn't like to share on GitHub feel free to use the email firebase-ios-sdk-6404@google.com to share it with us privately.

glaures-ioki commented 4 years ago

@maksymmalyhin I will have a talk with my team but I don't think I will be able to send the project. A call with shared screen sounds more realistic.

Thank you for your commitment to solving this issue 🙂 I keep you posted

maksymmalyhin commented 4 years ago

@glaures-ioki A screen sharing meeting will also be helpful. Feel free to send emails and time when you'll be available to the email to set it up.

As for the project, I may suggest a way to get a minimal required sharable project. I would take the full project and start dropping pieces and dependencies from it until the issue is not reproducible. Going through this exercise actually may help to detect the actual issue even faster. I would imagine that the result may be just a small project with some dependencies and almost empty App Delegate.

maksymmalyhin commented 4 years ago

Notes.

Things observed in the projects with the issue we've seen so far:

static Firebase frameworks are used a dynamic framework. Firebase is not used in the app directly
Firebase static frameworks may be linked with the dynamic framework or with the app executable binary directly
some Firebase and GDT classes are not loaded to the Objective-C runtime, as a result required initialization code in +load methods is not executed, so Firebase is not functioning as expected (e.g. crashes are not uploaded)
direct call to an unloaded class triggers its loading, so the Firebase SDK distribution contains all required classes
attempts to add -all_load or -force_load to the app or the dynamic framework linker flags didn't help (though more investigation is required here to make sure the flags are added to a proper target)

We still need a project we can experiment as iterations over a video conference are a bit slow.

paulb777 commented 4 years ago

Is -ObjC used when for the dynamic framework builds that link in Firebase?

maksymmalyhin commented 4 years ago

@paulb777 As far as we could observe -ObjC flag was set for both the dynamic framework and the app.

google-oss-bot commented 4 years ago

Hey @puneet-egym. We need more information to resolve this issue but there hasn't been an update in 5 weekdays. I'm marking the issue as stale and if there are no new updates in the next 5 days I will close it automatically.

If you have more information that will help us get to the bottom of this, just add a comment!

glaures-ioki commented 4 years ago

As explained in https://github.com/firebase/firebase-ios-sdk/issues/6464#issuecomment-707630052 we managed to fix our issue this way. Sorry for all the trouble. @puneet-egym, it could be the same issue for you too.

ghost commented 4 years ago

@glaures-ioki Thanks a lot for your comment. Yes, linking the GoogleDataTransport.framework has solved the issue for us as well 👍

ghost commented 4 years ago

Linking the GoogleDataTransport.framework has solved the issue for us

firebase / firebase-ios-sdk

Crashes and Non-Fatals are not getting logged #6404

[REQUIRED] Step 1: Describe your environment

[REQUIRED] Step 2: Describe the problem