Debugging a Non Reproducible Crash

Today, I'm going to tell you a story, the story of a bug and our fight against this bug. A bug so vicious and cruel that it actually caused us no less than 20,000 crashes. But introductions first.

Hi, everyone. I'm Alex. I'm very excited to be here at React Advanced London. I'm a tech lead at BAM. We're based in Paris and we develop mobile apps in Flutter, Native, and of course React Native. And our story begins in October. And we're a team of nine people, and we're very happy and proud to release version 4.3 of our app. Why are we so happy and proud? Well, because actually we were getting ready for our October 11th live event that the app was covering, and we were adding a lot of essential features to the app. Super. We're super happy.

But then, the unexpected hope occurs. Suddenly, our crash rate actually goes up significantly. And actually, our crash reporting tool that we're using, Sentry, is under heavy fire. It's reporting an exception every minute, then, a lot of exceptions every minute. Then, it's basically an exception every second, and it's getting overwhelming. And all of those exceptions are a bit different, but they're all kind of have the same shape. They're like this. Basically, it's a JS application illegal argument exception error while updating a style property in a shadownode of type a react Native component.

And so, well, first thought, is like, well, you know, we did QA this release, we did test it out a lot. Why did we not see this happening? And also, if you search a bit more about this error, this tends to happen if you set a wrong value to a style. For example, if I set padding top to NAN, not a number, this is what would occur. So it kind of sounds like something quite easy to detect. So, like, well, maybe it happens only in certain extreme cases that we have not tested properly before. But it turns out that Sentry is basically reporting that it happens for every user, every Android device so this is an Android issue only, but all Android devices are affected. And also in our app you can actually favor the team, for example, to change a bit the experience of the app. But it doesn't matter whichever team you're actually favoriting doesn't impact this. You're getting the crash.

All right. Well, we have a big crash, we have a big fire to put out, so let's start by trying to reproduce the crash, right? So fortunately we configured for Sentry or crash reporting tool to tell us what the user was doing before triggering the crash. So here we see that the user is actually opening the app, starting the first screen of the app, which is called Home. And boom, actually it crashes instantly.

All right, so basically you're telling me that it affects any device, it crashes on startup, it affects any user and we can't reproduce it? We've never seen it before, how is that even possible?

All right, well I guess step two, if you can't really reproduce, is analyzing the stack trace. So let's take a look. Okay, I did say that we have several different errors. I guess, let's take a look at the first one. So this one is an array index out of bound exception. It's a Java error. And it's happening in the class called SimplePool and it's a class from Android v4 support library. And it's happening in SimplePool.release, like 116 of pools.java. And well, to be honest, at this point I'm like I don't even know what SimplePool is. And I don't even know why I'm even in the Android source code. Like there's a big fire to put out and it feels like it's going to take a lot of time to actually figure out what's going on because I don't really understand this. So I guess let's find an easier solution to put out the fire.

So one idea would be, well, could we just roll back our release? Well, if you're a mobile app developer you know that we can't actually really roll back the release? We actually have to deploy a new release with the old code. It's kind of annoying and it means that certain users, you know, the users will get an update of the app just reverting everything. And at this point in time, we actually know that our crash rate is about 10%. So it seems that basically a user opening the app has one out of 10 chances to crash the app. But it seems that whenever they try to restore it, it works. And also, this release has actually great value for users. It turned out to be one of the highest-rated releases despite this outstanding crash. So we thought, well, no, let's not roll back. It's not the end of the world. It's outrageously big to have 10% crash rate, but let's try to fix it in another way.

All right, we know that the crash rate is 10%, so I'm like, okay, I can devise a battle plan. I'm just going to take six Android devices, I'm going to trigger with a script 10 app launch per device, so statistically I should get like five to 10 crashes, right? And at least that would be some kind of reproduction. I would be able to finally see the issue, and if I get a fix, then I would be able to test it out. The result was that I didn't get any crashes.

None whatsoever. Quite unlucky. So okay, I guess we need to find something else. So another idea was what actually changed. Our previous release was not crashing, this release is crashing. So what did we introduce between the two releases that actually crashed the app?

So my thought at this point was maybe we should take a look at the native dependencies we upgraded. Because well, this is a Java exception, so it happens in the native code, so probably the culprits is a native dependency that we upgraded. And it turns out that we upgraded two native dependencies since the last release. First one was React Native SVG, and the second one was native navigation. So you probably don't know native navigation. So it's actually a fork that we made from an Airbnb navigation library, which is using well, native navigation. And it turns out that we ourselves added some features to improve the performance at startup, right. So it sounds like a very nice culprit, you know, we upgraded it to improve the performance at startup, we get crashes at startup. Okay, it sounds like this one should be the culprit behind our crashes.

So as you may know, in the Play Store, you can actually roll out a new version of your app to only a subset of your user. So for example, you can just roll out the new version to like 10% of your users. So that allows us to devise a new battle plan. If native navigation is actually the culprit, we can just test it out. We don't create native navigation. We release a new version that we roll out only for 10% of our users. We check back, we should be able to see in like an hour or so if the new release is actually successful. And if it is successful, then we roll out to everybody the new release because, well, the crash is fixed, yay. Yeah, but what if it actually doesn't fix the crash? Okay, I guess in this case, let's just downgrade the other one, the SVG library, and, well, we do the same. We roll out for 10% of our users. We check back. If success, yay, full rollout, okay, cool, we won. But what if again that didn't fix the crash? So this would actually mean that if it still doesn't fix the crash, it would mean that we upgraded twice our app and every time, each time, 10% of our users got an update which actually didn't do anything and didn't fix everything, didn't fix the crash. That's actually a source of potential uninstall, like when a user gets a lot of upgrades of his app but it doesn't do anything for him. It happens sometimes that a user actually uninstalled the app because of this. So to be honest, that plan is yeah, it's kind of dumb.

So, all right. I guess at this point, yeah we need to go deeper. We really need to understand the bug and we really need to analyze it. So let's take a look again. Our bug, as you recall, was an array index out of bounds exception. All right. Let's take a look at where it was happening. It was happening, as you might remember, in a class called SimplePool inside the Android v4 support library code. And basically the bug was this. We have an array of objects called mPool and we have an index called mPoolSize and we're trying to access this array at index mPoolSize which apparently equals minus one. So now you don't need to be a Java expert developer to know that accessing an array at index minus one is really not a good idea. So you can understand where the crash is coming from. So mPoolSize value is minus one which is not good. So the question now is what actually can modify mPoolSize? So mPoolSize is actually modified only in this place. It's initialized to ten and then it's only being decreased in this function called acquire inside simplePool. This is the only place where mPoolSize actually changes in this function and it gets decreased but you might notice something right there's actually a condition there to protect it from being below zero. Here is if mPoolSize is over zero then decrease mPoolSize. So it kind of sounds impossible that mPoolSize would become minus one because if mPoolSize is zero you cannot decrease it even further so that really sounds impossible.

Okay, I guess it's time to bring out our ultimate weapon, and of course, I'm talking about the debugger. So, alright, let's open Android Studio and go to the famous function, acquire. In the stack traces, we noticed that this function was called from the React Native code in the class called dynamic from map and the function create. We put a breakpoint there and observed that the threads reported by Android Studio were MQT native modules, except for the 34th hit, which was the main thread. This gave us a clue that the function dynamic from map create could be called from different threads. We also discovered that the property being updated was an SVG property, not a React Native style property. It turns out that the SVG upgrade caused the bug.

But on hit 34 the thread that was used is the main thread so basically what this means is so I was actually not triggering the bug in this case but this gave me a very big clue. This function dynamic from map create could be called from different threads. If we take a look at hit 34 actually we notice that in this case the property being updated was a property called fill and well this really doesn't sound like a React Native style property right? Indeed, it's actually an SVG property. So it was the SVG upgrade all along that actually caused this bug. So let's see what actually can happen.

So React Native SVG, we upgrade it to v7 and they started using this code dynamic from app create to improve the performance of native SVG animations. But they were using it from the main thread while React Native was actually using it from MQT native modules. So what can actually happen? This impossible condition, well when you have something impossible happening in Java it's usually because of thread safety. You know as JavaScript developers we're not really used to having multiple threads and having to deal with that, but when you do React Native you get also Java in the mix. So you get thread safety in the mix. So here this impossible condition, well it could happen that two threads, thread A and thread B could actually go pretty much at the same time on the condition if amplesize over zero and think it is over zero, and then they both enter the condition at the same time and so it means that they both decrease it. It's kind of like this. Thread A sees amplesize over zero is true, cool, but it doesn't have time to decrease yet, it doesn't have time to get out of the function yet because thread B is actually entering the condition as well and checking amplesize over zero is true. And if at the beginning amplesize is one, then it's again one when we check the condition for thread B. And then, what happens is they actually both decrease amplesize, so it becomes zero and then minus one. So, wow, we actually know where this is coming from and this is actually why it was so hard to reproduce because this is a race condition that was very tricky to actually trigger. So let's fix.

So when we investigated, we found that there was a pull request on React Native dealing with this, dealing with thread safety actually on dynamic from map creates. And so, with collaboration with the React Native core contributor that submitted the pull request and React Native SVG maintainers, we devised a final battle plan. We patched React Native locally, we deployed this version to 10% of our users just in case to check, and then, of course, check back. Was it successful? Yes. Finally. We fixed it and our crash rate was back to normal. Whoo! Alright. Well, this was fantastic. But maybe a few takeaways from this. First one is this. You should use your crash rewarding tool extensively, and you should configure it to be able to use it because you're going to get crashes in production, and probably you're going to get crashes that you can't reproduce. So you should know what the user is doing before triggering the crash. Out of the box, you're not necessarily going to have this on your crash rewarding tool, so you should set it up so that it's easy to see, for example, the screens that your user is navigating to.

You should also add as many details about the user as possible, of course, in a GDPR-friendly manner. For example, in our case, adding what teams the user was actually favoriting to change his experience, because sometimes you trigger bugs only in certain cases in your app, of course.

Then you should, of course, monitor your release health. 10% crash rate, of course, is outstanding. It's really, really bad. 0.2% crash rate is a bit better. The market standard is about 0.3, 0.4 for Androids. It's even lower for iOS.

And if you actually do that, it also allows you to do one thing, protect your users. And that's what we did after this. Every time we're deploying a new release, we were actually rolling it out to 10% of our users. Of course, we should never have crashes, outstanding crashes like this in those 10%, but in case it actually does happen, at least we impacted only 10% of our users. So, the rest of the users, they have no impact. And of course, that means you're able to know if the release was successful, so you're able to monitor the health of your release.

And of course, you have time between the initial rollout and, for example, in our case, we had the live event on October 11. We did the release on October 9. Not really a good idea.

The final one is this. You can actually learn a lot by digging deeper. I've never learned as many things as when I was actually going through a bug that I could not reproduce, and I dived in deeper into the source code of libraries I was using, and every time, I learned so much.

And that's it. Thank you for watching, and do hit me up if you have any questions on the Discord channel or on Twitter.