Debugging a Non Reproducible Crash


POV: Your app has a crash affecting thousands of users, but for the life of you, you can't reproduce it and have no idea what's causing it. Hear the story of an epic struggle to vanquish a non reproducible bug and learn what to do (and what not to do) when facing such a foe.


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 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 shadow node of type 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 favorite a team, for example, to change a bit the experience of the app. But it doesn't matter which ever 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? 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, 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 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, you know, 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. So 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. So all right, we know that the crash rate is 10%. So I'm like, okay, I can devise a battle plan. You know, 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. So it sounds like a very nice culprit. 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 grade 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. And, 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. F-success. Yeah. 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 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 object 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. Well, it's initialized to 10, 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. There 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. Against bug, ultimate weapon, the debugger. So all right, let's open Android Studio. And so the famous function which actually decreases mPoolSize was the function acquire. And in the stack traces that we were seeing, we would see that this was called from the React Native code in the class called dynamic from map, and the function create. So exactly this line. So all right, let's put a breakpoint there. So the first hit of the breakpoint that I saw, so basically I just ran the app. And well, I was hitting the first breakpoint quite fast. And it's telling me basically that, well, actually dynamic from map is used by React Native to store component style properties. So here we're updating the width of a certain component. So you can imagine that this is actually going to happen a lot because, well, every time basically we modify a style, we hit the breakpoint. So yeah, breakpoint hit two was kind of similar. And actually, yeah, I clicked basically 34 times on the play button and had similar results. But oh, actually, revelation at the 34th click. Because from hit one to 33, I'm getting something like this, hit 34, I'm getting something like this. There is a very subtle difference in those hits. Because from hit one to 33, the thread that Android Studio was reporting is MQT native modules. And, well, this is the thread that React Native is usually using to deal with native code through the bridge. 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, we notice that in this case, the property being updated was a property called fill. And 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 upgraded to v7, and they started using this code. Dynamic from map 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 ample size 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 ample size 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 ample size over zero is true. And if at the beginning, ample size is one, then, you know, it's again one when we check the condition for thread B. And then what happens is they actually both decrease ample size, so it becomes zero, and then minus one. So wow, we have actually, 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 this 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. All right. Well, this was fantastic. But maybe a few takeaways from this. First one is this. You should use your crash reporting 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 reporting 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. And you should, of course, monitor your release health. 10% crash rate, of course, is outstanding. It's really, really bad. 19.8, I mean 0.2% crash rate is a bit better. The market standard is about 0.3, 0.4 for Android. 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 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. And the final one is this. You can actually learn a lot by digging deeper. I have 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 code, 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. Thank you.
20 min
25 Oct, 2021

Check out more articles and videos

We constantly think of articles and videos that might spark Git people interest / skill us up or help building a stellar career

Workshops on related topic