React-native: [Android] Extreme lag after upgrade to 0.39.2 and 0.40.0

Created on 10 Jan 2017  ยท  107Comments  ยท  Source: facebook/react-native

Description

Updating from 0.36.0 to 0.39.2 and 0.40.0 renders the app unusable after minimal interaction. The javascript thread slowly grinds to a halt until it becomes unresponsive. Native UI, such as scrolling or native animations is unaffected. Problem persists with 0.41.0-rc.0

It works perfectly well with 0.38.0

Reproduction

I managed to reproduce this in a freshly installed app with an infinite scroll list containing rows with images. With 0.40.0, the JS driven animation begins to lag after only ~150 items. WIth 0.38.0, animation stays smooth as long as there is no rendering.

See attached videos below:
0.38.0
0.40.0

Test app can be found here

A relative StackOverflow question.

Solution

I suspect the new C-based CSS implementation, as that is the only major change from 0.38 to 0.39. Another reason could be a problem with removeClippedSubviews.

Additional Information

  • React Native version: 0.39.2 / 0.40.0
  • Platform: Android
  • Operating System: MacOS
Locked

Most helpful comment

I've investigated the problem with a simplified version of the OP test app: https://gist.github.com/ncuillery/0b576650cebb34317e4c953e0efb56d5

I've removed the animation and replaced all the images with Text elements to be sure that it has nothing to do with Fresco and image loading. I've also activated the spy on the MessageQueue.

I think I have a scenario that isolate the problem:

  • Run the app with Android Studio
  • Open the Android monitor in Android Studio
  • Open the perf monitor in app
  • Scroll to index 500 (when the loading of further items tends to be slow on my device)
  • Wait for the UI to be responsive (I've added a Toast when touching the first blue Text element)
  • Scroll to top as fast as your finger can do!

๐Ÿ‘‰ The UI isn't responsive for a long time, the Touchable element has no effect.
๐Ÿ‘‰ The CPU is busy at 20% continuously
๐Ÿ‘‰ No message appears in logcat, absolutely nothing is logged in the MessageQueue
๐Ÿ‘‰ The in-app Perf monitor shows UI thread at ~56fps and JS thread at ~16fps

Finally, after an important amount of time (could be more than 1 minute), it seems that the system gets unblocked:

  • The UI is responsive again, the toast shows up immediately after touching
  • The CPU becomes idle: capture d ecran 2017-03-08 a 21 53 10
  • I can see the bridge messages in logcat again
  • The JS thread is back to ~55fps

Scrolling back to index 500 produces the exact same situation.

When I follow the same scenario with 0.38.0. There is no JS thread drop rate when scrolling fast. The CPU turns idle as soon as I stop scrolling.

With 0.39, the behavior is the same as 0.40.

In conclusion, I would say that the problem appears in 0.39.0. It seems that a time-consumer (and CPU-consumer) task is triggered when scrolling the ListView, this task makes the bridge completely stuck until it is finished. That's why any feature requiring a communication via the bridge (JS anim, datafetching, navigation, rendering components, ...) is affected.

All 107 comments

Were you able to confirm that the slowdown is because of more onLayout callbacks happening without actual changes to layout?

@sahrens Yes, I built RN from source from the commit before and all was good ...

I can confirm this problem in my application, i have updated from 0.36 to 0.40 and UI becomes unusable after render 100 items in a simple listview where the rows are only text and image.
Today I have tested 0.41.0-rc.0 and master but problem is still present.

I have tested today 0.41.0-rc.1 - still the same.

I'm facing the same issue, any progress or workaround?

Have no idea what to do. It actually forced me to stop working on ย my project(( I have no time to dig into debugging and so on.

ะ’ั‚ะพั€ะฝะธะบ, 31 ัะฝะฒะฐั€ั 2017, 17:05 +03:00 ะพั‚ Neo notifications@github.com:

I'm facing the same issue, any progress or workaround?
โ€”
You are receiving this because you commented.
Reply to this email directly, view it on GitHub , or mute the thread .

two screenshots of android profiler when I scroll listview:

ygnodecalculatelayout

nativerunnable

I want to add my voice to this chorus. I upgraded from 0.34.1 to 0.40. I was pleasantly surprised by some of the improvements (Dailymotion working well within the Webview, some keyboard problems fixed, screen rotation with better behavior) but then I realised the performance drop. I was close to releasing my app but the problem is so bad I have to wait. Still waiting. Coded as a stop-gap a simple page trick with only 50 elements per page to ensure smooth scrolling and touch responses. And this is is on a Samsung S6. Performance is significantly worse on lower-end/older devices.
This is an extremely serious, almost fatal issue for many projects. I hope it gets fixed very soon.

We're seeing the exact same issue here as well, iOS works fine, Android has become very laggy post update.

Same here
@sahrens Any Idea who is the right person to approach with this issue?

Same here. We had to downgrade to 0.38.

And same here. Hopefully this can be addressed soon.

@K-Leon I think that @astreet is the author of the commit (https://github.com/facebook/react-native/commit/d63ba47b59e3261403800c1f741d979a089efb48) introducing the new CSS engine.

This wouldn't be related to that commit -- it's more likely related to https://github.com/facebook/react-native/pull/11222 (is anyone able to try reverting that locally and see if the problems go away?)

I'll post internally and try to get someone on it.

The commit of #11222 was cherry-picked into 0.38 and 0.39. People are reporting the bug doesn't happen on 0.38. So maybe this PR is not the root cause?

0.38.0 is different from 0.38.1
I haven't test the reverting thing, but I have to say there are a lot of layout issues on Android when I'm trying to implement a HTML render, then I switched to Nodes which is still experimental and all the LAYOUT DON'T UPDATE issues on Android are gone.
But when I upgrade my app to the latest version of RN, I scroll a list to load more data, the following interactions become so buggy that there is nearly no response on touch, and I have to wait for several seconds

Reverting that commit makes quite a large difference to us - I'm not 100% certain that performance is back to what it was before 0.39 - we'll continue testing.

which commit should I revert to temporarily fix the problem?

It depends of your RN version as it was cherry-picked in the previous releases:
>=0.40: https://github.com/facebook/react-native/commit/fb230000a8d70fbc1e4c6ccfd9470de838554371
0.39: https://github.com/facebook/react-native/commit/4cd4b4b92207d0d77ef73374a6ba111103a7156d
0.38 https://github.com/facebook/react-native/commit/9a13def8b6fbb2ae3d1f31f63066f87527e56fcd

For 0.38, a simple way to revert it is to switch from 0.38.1 to 0.38 and see if the problem goes away. I don't have a way to reproduce the bug so I can't test it.

But I guess the final solution to this is not to simply revert this commit because it fixes a bug for me and for other people. Basically, we have to get rid of the performance problem without breaking what it solved.

I have a fix in review internally that I'll hopefully get in today. I'll make sure it gets cherry-picked into the next release.

@astreet
Cool! Maybe It is worth to cherry-pick the fix into some older releases, too? Still many apps use 0.39 or 0.38 because of breaking changes in 0.40.

I'm not sure on the feasibility of that, @mkonicek?

Fix is in: https://github.com/facebook/react-native/commit/15429e333f8fd80c4778f222058dbb16278cf625

Let's make sure it doesn't break anything internally and then we can see about getting it cherry-picked.

Just tested the fix on my test repo with the bug and it didn't break!
I hope the performance problem is solved for the others and both world will be happy ๐Ÿ‘

Yes, I kept your original PR in mind :) Thanks for checking and reporting back!

Seems that this commit cannot fix my issue. My issue is that after scrolling a large list for a while, the touch response is extremely slow, the Touchable onPress event was triggered after I physically pressed the screen for 3-4 seconds. The JS thread fps dropped to 30 fps while I am scrolling the list.

RN: 0.40
Dev mode: off

@ming436534: and that was a regression upon upgrading 0.39.2 to 0.40.0?

@sdcooke: can you verify that this fix improves your perf issues in the same way the revert did?

Hi @astreet Thank you for the fix. I too had performance issue with my app. I would like to know how do I get the fix for my app. My react-native version is 0.41.2. Do I just upgrade the react-native?

@astreet this fix has the same impact as reverting.

@KakarN You'll probably need to wait until the next release of react native, or build the master version from source. We haven't yet released a new build that has this fix but I'll make sure we do soon.

oK @astreet Will be waiting for it. Thanks again.

@ming436534 : aah. that was exactly my issue. Big lag after 50-100 components (with external images) The press is acknowledged immediately (I can see it with a console log) but it would take 3-4 (or more) seconds before displaying what it is supposed to. I really hope @astreet 's fix solves it and makes it to 0.42. Otherwise, I'll revert to 0.38 :(. I can't wait much longer before launching the app.
(PS: Can anyone suggest an easy (read not too painful) way to downgrade RN? I'm looking it up but so far, I'm not sure which way to go.)

@astreet any plan to make a cherry-pick?

Unfortunately, no: See @mkonicek's post here: https://www.facebook.com/groups/react.native.community/permalink/931576460311266/

It looks like this could potentially be a breaking change for libraries that are dependent on the previous over-zealous onLayout behavior.

Is there a fix available 1 March?

The fix will show up in v43 (the march 2017 release): see https://github.com/facebook/react-native/releases

The 0.43 RC will likely be available around 9am CET (Central European Time)

I have updated to v0.43.0-rc.0 and it's still very slow. ListView gives a lot of lagg.

@sahrens: there might be other listview lag issues besides the one I fixed. Do we have any public resources for people to be able to debug?

Could be a million things. General Android performance tooling? Is there a public fbsystrace equivalent? If the issue is just JS, you can try adding

require('InteractionStallDebugger').install();

to your bundle/early in your app init.

I also upgraded to v0.43.0-rc.0, like @RichardLindhout. If anything, it felt even slower. With 0.41, my Galaxy S6 was fine with 50 items per page, now it's around 25 (more than that and I have to wait 4-5 seconds before getting a display). My items render as a picture, some text and icons, and are connected to redux. So not the simplest components but still, the same that used to fit perfectly by hundreds in ListView 0.34.1 version.
I'm now trying to make FlatList work. Having some issues with it but I haven't tried hard enough yet.
My last hope before seppuku :-D

@sahrens it performs just normal on ios. Before I updated to later versions of React Native the app performed not the same as (a recyclerview in Android) but still it worked wel enough. Now when I scroll the listview my whole app (only on Android) becomes just not usable all the buttons and navigation are slow. When I select items in the listview they become selected after sometimes 10 seconds. If I don't scoll they are just fast. @ksegla Let me know if that change does make a difference!

@RichardLindhout If you're referencing FlatList, first of all I was being a total idiot as I was importing and using an imaginary FlatView that, for some weird reason, refused to be a real thing :-). Once I realised my mistake, FlatList was actually simple to use (though I had to bind the render function in order to see my component props).

FlatList does seem a lot faster (though it seems that it just skips out rendering components when you scroll too fast). Bad news is: the problem is still there. It takes even longer to respond to touches. I no longer think it's a ListView or FlatList problem only. It may be something deeper. I spent quite some time experimenting with 0.42 and the prerelease 0.43. ListView, FlatList. Worse response times than 0.41. So I just rolled back to 0.41, where at least my 50-component-a-page-trick consistently holds: quasi-immediate feedback-and-activity after fast scrolling 50 components and pressing one. 0.42 and 0.43 were taking much longer.

As @sahrens said, it may be a million of things. I will try his suggestion (since the fps drop only affects JS) but I'm now thinking that either it's something very specific on our side and eventually we'll figure out a way to adapt to the new RNs or it's a big thing that will prompt major changes once more developers switch to the newest versions. If I uncover anything new, I will report it here or may be we should create a new issue (?). @ramilushev Did 0.42 or 0.43-rc solve your original issue?

@ksegla Could you do a git bisect to isolate the bad commit?

@ksegla I can confirm that the issue is not fixed. Tested with 0.43.0-rc.0 with the test app from the OP (found here).

For the lazy - It's basically an infinite list with items consisting of images, and an absolute positioned block that is animated constantly from left to right with a JS driven animation (see videos from OP).

The JS driven animation (native is perfectly fine) is completely blocked for a few seconds after rendering of new items in the list has finished. Not only that, but after it resumes, it's frame-rate seems to drop proportional to the amount of rendered items. VIDEO

Same issue here after upgrading to 0.40+

Our brownfield app uses a ListView mounted with 1000 placeholders (~20 are rendered on mount). It is immediately slow to respond to touch event (~2 or 3 seconds). When scrolling, the datafetching and the placeholders replacement takes a huge amount of time.

I have spied the MessageQueue and it looks like every message needs a considerable effort to be read (Android monitor shows that the device CPU rates 40% until the MessageQueue is not empty) even if the amount of messages seems quite reasonable to me.

I can see that @astreet fix https://github.com/facebook/react-native/commit/15429e333f8fd80c4778f222058dbb16278cf625 (cherry-picked in the 0.43 branch) removes unnecessary onLayout which lightens the queue, but I can't feel any noticeable UI improvements. The real problem is still here.

What messages are you seeing in your queue? Do you have a app I can repro with?

@K-Leon My app depends on some libraries that are having hard time with downgrading (some radical adaptation to the breaking changes in 0.40, I guess). So even reverting to 0.38.0, which seems to be a safe version to start the bisect with, proved painful with errors here and there. Right now, real-life work is breathing down my neck so I don't have the time to go full app debugging or coding/experimenting with simple examples.
-- This sounds like "I don't wanna do the work. I'd rather come here and whine about the issue" :-) but it's true

We're having trouble reproducing the lag being described here.

Can you provide more details? The bridge messages @astreet asked for, what hardware and API version you're running on, and anything else you can think of? Do other react native apps work ok on your device, like the Exponent app? Facebook marketplace? Li.st?

I have attempted to debug this issue using the InteractionStallDebugger in our own app, it looks like NavigationExperimental or Native Animation changes may be the cause of the stalls.

NavigationTransitioner is the top "time waster" when using the tool:

| Inclusive wasted time (ms) | Instance count | Owner > Component | Render count |
|---|---|---|---|
| 1956 | 8 | NavigationTransitioner > View | 8 |

I'm not certain this is the cause yet, I will try to reproduce in an example project.

RN 0.43.0-rc

Bridge messages

@sahrens @astreet The messages are pretty the same between my brownfield app and the test app linked in the OP.

I'm able to repro the lag on my Samsung SM-G930F (Galaxy S7) using Android 6.0.1, API 23. Other RN apps work well, the test app using version 0.38 works well too.

I've ran the test app in RN 0.40.0 and save the full output when scrolling from index 250 to 300.

Here is some samples from the output:

JS animation of the orange bar

03-08 12:37:31.860 9886-23047/com.zero40app I/ReactNativeJS: N->JS : JSTimersExecution.callTimers([[3709]])
03-08 12:37:31.860 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.updateView([230,"RCTView",{"transform":[{"translateX":44.06070971011271}]}])
03-08 12:37:31.870 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.updateView([232,"RCTView",{"transform":[{"translateX":44.06070971011271}]}])
03-08 12:37:31.880 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.updateView([233,"RCTView",{"transform":[{"translateX":44.06070971011271}]}])
03-08 12:37:31.880 9886-23047/com.zero40app I/ReactNativeJS: JS->N : Timing.createTimer([3710,1,1488973051891,false])

A bunch of these while I touch the screen:

03-08 12:37:33.340 9886-23047/com.zero40app I/ReactNativeJS: N->JS : RCTEventEmitter.receiveEvent([5,"topScroll",{"responderIgnoreScroll":true,"target":5,"layoutMeasurement":{"height":507.4285583496094,"width":411.4285583496094},"contentSize":{"height":77440,"width":411.4285583496094},"contentOffset":{"y":75053.7109375,"x":0},"contentInset":{"right":0,"left":0,"bottom":0,"top":0}}])
03-08 12:37:33.360 9886-23047/com.zero40app I/ReactNativeJS: N->JS : RCTEventEmitter.receiveEvent([5,"topScroll",{"responderIgnoreScroll":true,"target":5,"layoutMeasurement":{"height":507.4285583496094,"width":411.4285583496094},"contentSize":{"height":77440,"width":411.4285583496094},"contentOffset":{"y":75100.859375,"x":0},"contentInset":{"right":0,"left":0,"bottom":0,"top":0}}])
03-08 12:37:33.380 9886-23047/com.zero40app I/ReactNativeJS: N->JS : RCTEventEmitter.receiveEvent([5,"topScroll",{"responderIgnoreScroll":true,"target":5,"layoutMeasurement":{"height":507.4285583496094,"width":411.4285583496094},"contentSize":{"height":77440,"width":411.4285583496094},"contentOffset":{"y":75146.2890625,"x":0},"contentInset":{"right":0,"left":0,"bottom":0,"top":0}}])
03-08 12:37:33.400 9886-23047/com.zero40app I/ReactNativeJS: N->JS : RCTEventEmitter.receiveEvent([5,"topScroll",{"responderIgnoreScroll":true,"target":5,"layoutMeasurement":{"height":507.4285583496094,"width":411.4285583496094},"contentSize":{"height":77440,"width":411.4285583496094},"contentOffset":{"y":75187.7109375,"x":0},"contentInset":{"right":0,"left":0,"bottom":0,"top":0}}])
03-08 12:37:33.410 9886-23047/com.zero40app I/ReactNativeJS: N->JS : RCTEventEmitter.receiveEvent([5,"topScroll",{"responderIgnoreScroll":true,"target":5,"layoutMeasurement":{"height":507.4285583496094,"width":411.4285583496094},"contentSize":{"height":77440,"width":411.4285583496094},"contentOffset":{"y":75229.7109375,"x":0},"contentInset":{"right":0,"left":0,"bottom":0,"top":0}}])
03-08 12:37:33.430 9886-23047/com.zero40app I/ReactNativeJS: N->JS : RCTEventEmitter.receiveEvent([5,"topScroll",{"responderIgnoreScroll":true,"target":5,"layoutMeasurement":{"height":507.4285583496094,"width":411.4285583496094},"contentSize":{"height":77440,"width":411.4285583496094},"contentOffset":{"y":75269.7109375,"x":0},"contentInset":{"right":0,"left":0,"bottom":0,"top":0}}])
03-08 12:37:33.450 9886-23047/com.zero40app I/ReactNativeJS: N->JS : RCTEventEmitter.receiveEvent([5,"topScroll",{"responderIgnoreScroll":true,"target":5,"layoutMeasurement":{"height":507.4285583496094,"width":411.4285583496094},"contentSize":{"height":77440,"width":411.4285583496094},"contentOffset":{"y":75306,"x":0},"contentInset":{"right":0,"left":0,"bottom":0,"top":0}}])
03-08 12:37:33.460 9886-23047/com.zero40app I/ReactNativeJS: N->JS : RCTEventEmitter.receiveEvent([5,"topScroll",{"responderIgnoreScroll":true,"target":5,"layoutMeasurement":{"height":507.4285583496094,"width":411.4285583496094},"contentSize":{"height":77440,"width":411.4285583496094},"contentOffset":{"y":75343.4296875,"x":0},"contentInset":{"right":0,"left":0,"bottom":0,"top":0}}])
03-08 12:37:33.480 9886-23047/com.zero40app I/ReactNativeJS: N->JS : RCTEventEmitter.receiveEvent([5,"topScroll",{"responderIgnoreScroll":true,"target":5,"layoutMeasurement":{"height":507.4285583496094,"width":411.4285583496094},"contentSize":{"height":77440,"width":411.4285583496094},"contentOffset":{"y":75378.5703125,"x":0},"contentInset":{"right":0,"left":0,"bottom":0,"top":0}}])
03-08 12:37:33.500 9886-23047/com.zero40app I/ReactNativeJS: N->JS : RCTEventEmitter.receiveEvent([5,"topScroll",{"responderIgnoreScroll":true,"target":5,"layoutMeasurement":{"height":507.4285583496094,"width":411.4285583496094},"contentSize":{"height":77440,"width":411.4285583496094},"contentOffset":{"y":75412.5703125,"x":0},"contentInset":{"right":0,"left":0,"bottom":0,"top":0}}])

Mount of a ListView item:

03-08 12:37:33.980 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10768,"RCTView",1,{"alignItems":"stretch","height":150,"marginBottom":10,"justifyContent":"center"}])
03-08 12:37:33.990 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10769,"RCTView",1,{"height":20,"backgroundColor":-16711936,"alignItems":"center","justifyContent":"center"}])
03-08 12:37:33.990 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10770,"RCTText",1,{"lineHeight":20,"color":-40121,"accessible":true,"allowFontScaling":true,"ellipsizeMode":"tail"}])
03-08 12:37:33.990 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10772,"RCTRawText",1,{"text":"484"}])
03-08 12:37:33.990 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.setChildren([10770,[10772]])
03-08 12:37:33.990 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.setChildren([10769,[10770]])
03-08 12:37:33.990 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10773,"RCTView",1,{"flexDirection":"row","flexGrow":1,"backgroundColor":-65536,"flexWrap":"wrap","alignItems":"flex-start"}])
03-08 12:37:33.990 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10774,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053983"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.000 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10775,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053984"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.000 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10776,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053985"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.000 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10777,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053985"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.000 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10778,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053986"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.000 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10779,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053986"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.010 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10780,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053987"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.010 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10782,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053988"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.010 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10783,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053988"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.010 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10784,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053989"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.020 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10785,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053989"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.020 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10786,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053990"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.020 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10787,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053991"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.020 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10788,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053991"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.020 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.createView([10789,"RCTImageView",1,{"width":100,"height":100,"overflow":"hidden","borderWidth":1,"borderColor":-16744448,"shouldNotifyLoadEvents":false,"src":[{"uri":"http://lorempixel.com/400/400?date=1488973053992"}],"loadingIndicatorSrc":null}])
03-08 12:37:34.030 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.setChildren([10773,[10774,10775,10776,10777,10778,10779,10780,10782,10783,10784,10785,10786,10787,10788,10789]])
03-08 12:37:34.030 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.setChildren([10768,[10769,10773]])
03-08 12:37:34.030 9886-23047/com.zero40app I/ReactNativeJS: JS->N : UIManager.manageChildren([6,null,null,[10768],[484],null])

Some undesirable layout events (31 occurrences of this one in the full output):

RCTEventEmitter.receiveEvent([5,"topLayout",{"target":5,"layout":{"height":507.4285583496094,"width":411.4285583496094,"y":0,"x":0}}])

Those events are removed by 15429e3 (not 100% sure, I checked that 2 days ago by adding a onLayout event on my ListView item, not by spying the queue), but as you can read from the output, those events are literally drowned in the flood of messages.

Edit: the errors in the output W/System.err: remove failed: ENOENT (No such file or directory) : /data/user/0/com.zero40app/cache/image_cache/v2.ols100.1/94/cBsISkhjYbQRzy7GwKM2fd9rqTY.cnt are unrelated. It happens on my device with any RN apps since a long time, there is a problem with the fresco cache, see https://github.com/facebook/fresco/issues/1067

cc @janicduplessis

I've investigated the problem with a simplified version of the OP test app: https://gist.github.com/ncuillery/0b576650cebb34317e4c953e0efb56d5

I've removed the animation and replaced all the images with Text elements to be sure that it has nothing to do with Fresco and image loading. I've also activated the spy on the MessageQueue.

I think I have a scenario that isolate the problem:

  • Run the app with Android Studio
  • Open the Android monitor in Android Studio
  • Open the perf monitor in app
  • Scroll to index 500 (when the loading of further items tends to be slow on my device)
  • Wait for the UI to be responsive (I've added a Toast when touching the first blue Text element)
  • Scroll to top as fast as your finger can do!

๐Ÿ‘‰ The UI isn't responsive for a long time, the Touchable element has no effect.
๐Ÿ‘‰ The CPU is busy at 20% continuously
๐Ÿ‘‰ No message appears in logcat, absolutely nothing is logged in the MessageQueue
๐Ÿ‘‰ The in-app Perf monitor shows UI thread at ~56fps and JS thread at ~16fps

Finally, after an important amount of time (could be more than 1 minute), it seems that the system gets unblocked:

  • The UI is responsive again, the toast shows up immediately after touching
  • The CPU becomes idle: capture d ecran 2017-03-08 a 21 53 10
  • I can see the bridge messages in logcat again
  • The JS thread is back to ~55fps

Scrolling back to index 500 produces the exact same situation.

When I follow the same scenario with 0.38.0. There is no JS thread drop rate when scrolling fast. The CPU turns idle as soon as I stop scrolling.

With 0.39, the behavior is the same as 0.40.

In conclusion, I would say that the problem appears in 0.39.0. It seems that a time-consumer (and CPU-consumer) task is triggered when scrolling the ListView, this task makes the bridge completely stuck until it is finished. That's why any feature requiring a communication via the bridge (JS anim, datafetching, navigation, rendering components, ...) is affected.

I had observed a similar bug in our app where transition between screens was taking almost 5 seconds. On enabling spy mode, I found out that MessageQueue was blocked for exactly the same duration. So there was certainly some operation happening on the JS thread that blocked the UI updates (and everything else) until it finished.

screen shot 2017-02-09 at 1 26 27 pm

This is how we figured out the actual code causing the delay:

  • Filter out the MessageQueue logs from LogCat

  • Isolate the statements that got logged just before MessageQueue got blocked

  • There is a high probability that some event got triggered from there, that resulted in this blocking operation. In our case, as shown in the attached image, we were triggering an event as soon as the active screen went into onPause state (onDisappear). That event triggered a callback which executed a heavy synchronous operation on JS thread. This resulted in a significant delay in the opening of the next screen

  • After optimising that callback methodโ€™s code, everything started working fine

Lesson: It is really really important that any synchronous operation involving heavy computation that we may want to perform, should happen on the native side. JS thread should exclusively be for UI.

I have tested also on 0.43.rc0 and 0.43.rc1 and it is still happening (super slow responsiveness in ListView).
On 0.38 it is fine.
I also tried with a new FlatList and VirtualizedList components and the rendering is still really slow.

Hope this helps.

@astreet @ncuillery @ericvicenti I looked at the changelog for 0.39 and what seemed like the biggest change is the move to c++ based css layout (yoga). With that in mind I ran the test app and tried pausing the debugger during the lag to check out what the threads where doing at that time and something that came out is that the native-modules thread was always running jni_YGNodeCalculateLayout. I added some logs to UIManagerModule#onBatchComplete, where this function is called from and the results are interesting.

Here is logs when scrolling early when the ListView renders few items (start / end are onBatchComplete logs) https://gist.github.com/janicduplessis/01fa5d19052f7054199f5280842a9be9. Looks good, now let's compare to when the ListView is rendering about 300 items.

https://gist.github.com/janicduplessis/6e18bed6f888aeca8209c0e85ffc40a0

I annotated this one with what I was doing. You can see we receive the touch event from native to JS and it is processed in about 100ms and JS responds by show a toast. Now the native module thread seems completely stuck processing layout events from what I was scrolling before and finally after 8 seconds the breakpoint I put in ToastModule.java is hit.

Looks like the issue is that we are spending a huge amount of time doing layout on the native-module thread which blocks other native modules from doing their thing.

Questions / potential solutions

  • Why is scrolling causing so many layout recalculations
  • Why are we doing layout on the native-modules thread, was it like this before 0.39? This could be moved to thread separated from the other native modules.
  • Why is layout so slow? Looks like we are doing something wrong. Recalculating layout when adding new views in the list should not take many batches of over 50ms.

Nice find. I forwarded this thread to the yoga team at FB, but it would be nice if you could do some more analysis. Can you run a performance profiler while it's busy and see what function calls are hot? Profiling c++ code on Android is a bit tricky, but there are some tools:

https://android.googlesource.com/platform/system/extras/+/master/simpleperf/README.md

https://google.github.io/fplutil/android_ndk_perf.html

Etc

Seems like this is a RN issue with the yoga integration (becuase it only shows up on android). I'll look into it next week.

Nice find Janic, seems like strong evidence the native modules thread is being backed up. If it's an issue with layout, then moving layout to another thread unfortunately won't help with click latency since that will almost definitely need to do a layout itself. Can you share the code you used to collect those logs and I'll look into whether it seems we're doing more layouts than expected/if they're particularly more expensive? Also, just to be clear, this same code doesn't have this issue on iOS, right?

@astreet I haven't tested on iOS but according to this thread it happens on iOS only. I simply logged the time it took to run dispatchViewUpdates here https://github.com/facebook/react-native/blob/master/ReactAndroid/src/main/java/com/facebook/react/uimanager/UIManagerModule.java#L533

@janicduplessis sorry, I meant can you link the code for the test app you were using?

Is this still a problem in android and iOS?

@astreet I used the code provided by @ncuillery in this gist https://gist.github.com/ncuillery/0b576650cebb34317e4c953e0efb56d5

@emilsjolander and I investigated, this is two different issues compounding on each other:

  1. There was a regression with the switch to native Yoga where, even though a layout hierarchy would be cached, we still copy the outputs from C to Java for the entire tree. This doesn't really show up for smaller screens, but for listviews with hundreds of rows, this could take upwards of 50ms.
  2. When we switched to the new C++ bridge, an optimization got removed where we wouldn't call onBatchComplete when there weren't actually any native modules calls (e.g. if we made a JS module call but JS didn't call any native modules).

These two combined so that on each frame, the scroll event from the list view would trigger an onBatchComplete in UIManager, which would trigger a re-layout (cached, so no actual layouting would happen), but then we'd spend 50ms+ copying the entire layout result into Java.

I'm currently landing a very simple diff that fixes 2. which for me which largely mitigates the problem. @emilsjolander will still be working on a fix for 1. this week hopefully since that's still bad, so I expect both fixes to be landed by next week.

Thanks @ncuillery and @janicduplessis for providing a repro and doing investigation!

BTW, a good way to investigate these issues yourself without having to put a bunch of logging statements in your code is to use Systrace. I wrote a guide to doing that here: https://facebook.github.io/react-native/releases/0.31/docs/android-ui-performance.html

As an example, here's the trace I captured scrolling through the app in the repro.

screen shot 2017-03-16 at 11 16 09

It shows the native module thread being backed up with layout calls (as Janic was able to gather as well). This is also why it's so important to have a good repro we share -- that way we can look at the exact issue people are running into with certainty :)

Fix for the missing bridge optimization is in master now: https://github.com/facebook/react-native/commit/c8d922b4670127c417d744a0a1412cc6ad961fef . This should help fix the majority of the problems people were seeing. Yoga fix will be landing soon.

Hi @astreet ,
Is there a way to cherry-pick this fix into 0.43.rc instead of waiting for 0.44.0rc version?

And 0.42.2 ๐Ÿ˜‰

ping @grabbou

Hey @grabbou ,
Is there a way to include this fix into 0.43.rc release instead of waiting for the next one?

As you can see from the comments, this is a really important performance fix.

Thanks :)

Yeah, I am back to work tomorrow and will release important updates. The
conference trip distracted me a bit.

On Thu, Mar 16, 2017, 18:37 Arsen Ghazaryan notifications@github.com
wrote:

Hey @grabbou https://github.com/grabbou ,
Is there a way to include this fix into 0.43.rc release instead of waiting
for the next one?

As you can see from the comments, this is a really important performance
fix.

Thanks :)

โ€”
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/facebook/react-native/issues/11809#issuecomment-287134554,
or mute the thread
https://github.com/notifications/unsubscribe-auth/ACWcxvcj-OUJmsc6_5ncCMbDs-ef7uaMks5rmXNsgaJpZM4Lfm7J
.

0.43.0-rc.3 released with the fix

Yoga fix has not landed yet. Hopeing today

Thanks a lot!
Now, let's wait for the Yoga fix :)

Yoga fix had to be reverted as it broke some unexpected things. We will work on getting it in as soon as possible.

Thanks for the update.

I just wanted to thank all the people involved in this ticket. I have to release a new version of my app in 2 weeks and was going crazy with the 10fps + 20% constant cpu usage. You're geniuses.
Have a nice week!

@emilsjolander Any update on the yoga fix?

Still working on it

Yoga fix has now landed

You rock @emilsjolander ! Which commit is it that fixed it ?

I'll cherry pick that were it makes sense. Not sure if it's already in
latest RC, I think I picked it just before it landed.

On Mon, Apr 3, 2017, 20:05 Tomas Roos notifications@github.com wrote:

You rock @emilsjolander https://github.com/emilsjolander !

โ€”
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/facebook/react-native/issues/11809#issuecomment-291224259,
or mute the thread
https://github.com/notifications/unsubscribe-auth/ACWcxgQu6d9mcoY7xE4K_X1_UuBRLoAsks5rsTT2gaJpZM4Lfm7J
.

great work @emilsjolander and Yoga ๐ŸŽ‰

You hit it first @grabbou ๐Ÿ˜‰

Hey @emilsjolander
Will this have any affect on IOS side also?
It will be great if you could provide a PR/Commit so we can see the files it is touching.

Thank you!!!

Many thanks! Any chance this could find its way into 0.43.1?
Or should we fork RN and Yoga and build RN with Yogas patch?

I'll cherry-pick it into 0.43.1 as well, but I'll do it tomorrow from
office. Depending on your time-zone, it might be there when you wake up :)

On Mon, 3 Apr 2017 at 21:09 Atticus White notifications@github.com wrote:

Many thanks! Any chance this could find its way into 0.43.1?
Or should we fork RN and Yoga and build RN with Yogas patch?

โ€”
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/facebook/react-native/issues/11809#issuecomment-291243101,
or mute the thread
https://github.com/notifications/unsubscribe-auth/ACWcxs4p2VdZamwHUy_2wFQBo2OTJtmrks5rsUQGgaJpZM4Lfm7J
.

I tested in 0.44.0-rc.0 and its fixed, thanks! :)

Hey @grabbou
Just wondering if you had time to cherry-pick it into 0.43.1 ?

Yeah, I've already talked to Emil about that. Will release one more version
later today

On Wed, Apr 5, 2017, 11:05 Andrew Jack notifications@github.com wrote:

@grabbou https://github.com/grabbou I noticed 0.43.1
https://github.com/facebook/react-native/commits/0.43-stable didn't
include the yoga fixes, is it possible to cherry pick them or do they
depend other commits?

The matching commits in React native are:
facebook/yoga@5884ab7
https://github.com/facebook/yoga/commit/5884ab7b76a66b2a5b22a8ebd164f7a9b8f551ed
= 759b8cc
https://github.com/facebook/react-native/commit/759b8ccf71ccf9a017be186327eb8701e760b21a
facebook/yoga@5112564
https://github.com/facebook/yoga/commit/5112564f083422194cdb1baf1a97c0308cbc14cb
= f1371ec
https://github.com/facebook/react-native/commit/f1371ec24c7fbe66ec80690f8dc7636dd30dbb3e

โ€”
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/facebook/react-native/issues/11809#issuecomment-291799789,
or mute the thread
https://github.com/notifications/unsubscribe-auth/ACWcxk5zfKD_hRk8hWwtOx3lf5gC-1dMks5rs1lqgaJpZM4Lfm7J
.

0.43.2 is now on Circle and should be on npm in like two hours. If anyone wants this to be cherry-picked into old release, please find the ticket [XXX] commits to cherry-pick and leave a note there.

Having said so, can this issue be closed now?

I have tested this and can confirm it is fixed. A big thanks to everyone involved!!! You can close this.

Are you sure this is fixed? I have just finished converting a screen from using ListView to SectionList and it resulted into it being completely unusable on my physical Android 5.0.1 device.

I'm on react-native v0.43.3.

It initializes slowly, taking at least 5 seconds for the initial render, then in the perf monitor the JS thread says -2.1 fps (yes, with a minus).

During this time the app is completely locked up, except for scrolling the list, which seems to work.

The -2.1 fps situation clears itself after 20+ seconds and returns to 60 fps

One interesting thing is that if I enable Remote JS Debugging the app never goes below 60 fps and everything is super fast. Also GenyMotion is super fast as well, just the device has issues (but not when JS is running via remote JS).

Any clues?

@andreialecu this issue affected ListView and SectionList similarly I believe, so if you weren't seeing any issues on ListView then my guess is you accidentally introduced some weird perf regression with your transition to SectionList. The fact that the debugger makes a difference also implies a different issue.

If you can't sort out the problem, can you provide a repro case/sample code?

It seems like switching JS Dev mode to off helped the problem somewhat, as did removing a few console.log statements I had and disabling redux-logger.

Now it renders almost instantly (or at least without any perceived lag), but the JS thread still stalls bouncing between -2.1 fps, 2.1 fps for close to 10 seconds until it recovers.

All my section headers and list items are PureComponents.

However, if I trim down the renderItem to a simple <Text>Hello World</Text>, it seems to take around 1 second to recover.

The original list item component itself is not super complicated, but has several nested <View>s. I did notice that the more I strip it down, the better performance gets.

This didn't seem to be as much of a problem with ListView.

And if I run it with Remote JS Debugging enabled, it is instant, not exhibiting the problem even with the original renderItem, it never drops below 55fps - not even for a milisecond.

Alright, I kept the code for the ListView and it is identical to the SectionList implementation, but it runs much faster and never drops a frame.

However, now that I got rid of the console.log statements and redux-logger, I see that the issue I was experiencing wasn't this one. I confused the slowness from https://github.com/evgenyrodionov/redux-logger/issues/32 with an issue in react-native rendering.

It still seems like SectionList and/or FlatList have problems, but probably unrelated to this particular issue.

I'm still having the weird issue that @andreialecu discussed earlier using 0.43.3. On a physical device our app seems to run incredibly slow becoming unresponsive unless I have remote debugging turned on.

Without remote debugging I will drop to -2.0 fps for 10-20 seconds and then will come back up. During this time the app is not responsive. When I turn on remote debugging I average 50-60 fps.

I do not have any console.logs or redux logger turned on. I have also created a new react-native project and moved my files over with the same issues. At first I thought it could be a redux / data store issue problem. The only problem i see with that is iOS would be affected also.

Any help / ideas would be appreciated.
react-native 0.43.3
react 16.0.0-alpha.6
react-navigation 1.0.0-beta.7
redux 3.5.2

@joshualcoffee Can you take and post a systrace (see https://github.com/facebook/react-native/issues/11809#issuecomment-287029912)?

@astreet Sure thing. I have created a few videos of a scaled down app vs a larger app.
https://www.dropbox.com/s/ay4mtejsxcmc8xx/2017_04_20_07_05_54.mp4?dl=0
This shows a scaled down app without using debug mode. You can see the frames drops to -2.1 and locking the device for a very short period.

https://www.dropbox.com/s/bh2dkjd8svh00uf/2017_04_20_07_08_23.mp4?dl=0
This shows the scaled down app using debug mode. You can see frames only drop for brief periods to draw / redraw elements. Also page transition are smooth.

https://www.dropbox.com/s/9qu0o93naqfsjmk/2017_04_20_07_14_57.mp4?dl=0
Production app with async calls and more elements to render. This shows both debug mode and non debug mode. You can see the device stays locked up for a time period without debug mode turned on.

Systrace:
https://www.dropbox.com/s/ztwulxavy7915hm/trace.html?dl=0
Nothing stands out to me other than my mqt_js thread does not seem to look like the one you pictured.

@joshualcoffee are you using the new FlatList? In my app, as previously mentioned, ListView performs better, however once I scroll down so that new elements are being rendered, I still notice slowdowns that otherwise do not occur when Remote JS Debugging is on.

In general, the entire app seems slightly faster with Remote JS Debugging than without, so I'm not sure why that would happen. I'm on a low powered Android device, but you would think that marshalling to the PC back and forth would negate any performance differences the PC would have compared to the device.

There is also a related react-navigation issue here: https://github.com/react-community/react-navigation/issues/706 which I also believe to be react-native related.

It's not surprising at all that that things would be faster with remote debugging compared to running on a slow Android device. The marshaling overhead is actually quite small compared to the computation.

Ahhh well that's good to know. I think the issue is comparing it to developing on iOS. Typically you will get slower performance when you have remote debugging on during iOS simulation. If this is typical than disregard my comments.

FlatList still seems to be a huge issue for android. Following up what @andreialecu, I had to switch back to ListView as the performance for FlatList was horrible. Im pretty sure I can get around most of the performance issues by fine tuning my connected components. I'm noticing re-renders when there should not be any.

Hey guys I'm noticing the exact thing @joshualcoffee is after upgrading to 0.43.4. Unusable slow performance but only on an iOS physical device in debug mode, yet turning on remote debugging actually solves the issue.

Only using <ListView />s

Did the fix mentioned above land in 0.43.4 or 0.44.0 or not at all yet? Thanks for the help!

react-native 0.43.4
react 16.0.0-alpha.6

Hello. I`ve same issue.
On android JS thread says -2.1 fps.
Downgrade react-native to 0.38.1 help me (but i want latest rn =))

Same after upgrading from 0.42 to 0.48.3

Was this page helpful?
0 / 5 - 0 ratings