I get a few slow frames from OpenGL ES 2.0 on Android. It is enough that they cause stuttering in the rendering. I added a few lines that output these two pieces of information in System.err:
- Average paint time over the last 60 frames ("Average paint time: 2")
- The frame took more than 10 ms to draw, g = GUI drawing time, w = world drawing time ("Slow frame !!! (29, g = 27, w = 2)")
I posted some sample output below this question, showing random slow frames.
This happens even when nothing in the scene changes. What can cause these intermittent slow frames? If I turn even further and see if everything is consistently slowing down, I don’t see anything. It just seems random. Garbage collection occurs only twice in this sample, so I would not have thought that a problem with the GC would be a problem. What else can make these frames take up so much time from time to time?
11-09 13:42:53.768: W/System.err(25924): Avg draw time: 2 11-09 13:42:54.839: W/System.err(25924): Avg draw time: 2 11-09 13:42:55.860: W/System.err(25924): Avg draw time: 2 11-09 13:42:56.881: W/System.err(25924): Avg draw time: 2 11-09 13:42:57.442: D/dalvikvm(25924): GC_CONCURRENT freed 1715K, 62% free 3619K/9379K, paused 1ms+2ms 11-09 13:42:57.912: W/System.err(25924): Avg draw time: 2 11-09 13:42:58.273: W/System.err(25924): Slow frame!!! (29, g=27, w=2) 11-09 13:42:58.924: W/System.err(25924): Avg draw time: 3 11-09 13:42:59.014: W/System.err(25924): Slow frame!!! (19, g=2, w=17) 11-09 13:42:59.955: W/System.err(25924): Avg draw time: 4 11-09 13:43:00.075: W/System.err(25924): Slow frame!!! (28, g=25, w=3) 11-09 13:43:00.445: W/System.err(25924): Slow frame!!! (20, g=9, w=11) 11-09 13:43:01.026: W/System.err(25924): Avg draw time: 4 11-09 13:43:02.037: W/System.err(25924): Avg draw time: 4 11-09 13:43:02.197: W/System.err(25924): Slow frame!!! (16, g=14, w=2) 11-09 13:43:02.227: W/System.err(25924): Slow frame!!! (16, g=4, w=12) 11-09 13:43:03.088: W/System.err(25924): Avg draw time: 5 11-09 13:43:03.218: W/System.err(25924): Slow frame!!! (13, g=8, w=5) 11-09 13:43:03.308: W/System.err(25924): Slow frame!!! (22, g=16, w=6) 11-09 13:43:03.318: W/System.err(25924): Slow frame!!! (14, g=10, w=4) 11-09 13:43:03.348: W/System.err(25924): Slow frame!!! (11, g=8, w=3) 11-09 13:43:04.109: W/System.err(25924): Avg draw time: 4 11-09 13:43:05.030: W/System.err(25924): Slow frame!!! (31, g=29, w=2) 11-09 13:43:05.060: W/System.err(25924): Slow frame!!! (11, g=3, w=8) 11-09 13:43:05.070: W/System.err(25924): Slow frame!!! (15, g=11, w=3) 11-09 13:43:05.150: W/System.err(25924): Avg draw time: 4 11-09 13:43:06.191: W/System.err(25924): Avg draw time: 2 11-09 13:43:07.202: W/System.err(25924): Avg draw time: 1 11-09 13:43:08.243: W/System.err(25924): Avg draw time: 3 11-09 13:43:09.275: W/System.err(25924): Avg draw time: 4 11-09 13:43:09.965: W/System.err(25924): Slow frame!!! (29, g=28, w=1) 11-09 13:43:10.025: D/dalvikvm(25924): GC_CONCURRENT freed 1721K, 62% free 3625K/9379K, paused 3ms+4ms 11-09 13:43:10.296: W/System.err(25924): Avg draw time: 4 11-09 13:43:10.736: W/System.err(25924): Slow frame!!! (14, g=11, w=2) 11-09 13:43:10.756: W/System.err(25924): Slow frame!!! (14, g=3, w=11) 11-09 13:43:10.776: W/System.err(25924): Slow frame!!! (14, g=1, w=13) 11-09 13:43:11.307: W/System.err(25924): Avg draw time: 4 11-09 13:43:11.337: W/System.err(25924): Slow frame!!! (17, g=3, w=14) 11-09 13:43:11.357: W/System.err(25924): Slow frame!!! (14, g=3, w=11) 11-09 13:43:11.387: W/System.err(25924): Slow frame!!! (12, g=2, w=10) 11-09 13:43:11.797: W/System.err(25924): Slow frame!!! (17, g=14, w=3) 11-09 13:43:12.328: W/System.err(25924): Avg draw time: 3 11-09 13:43:13.319: W/System.err(25924): Slow frame!!! (19, g=3, w=16) 11-09 13:43:13.349: W/System.err(25924): Avg draw time: 5 11-09 13:43:13.379: W/System.err(25924): Slow frame!!! (14, g=10, w=4) 11-09 13:43:13.970: W/System.err(25924): Slow frame!!! (14, g=11, w=3) 11-09 13:43:14.410: W/System.err(25924): Avg draw time: 4 11-09 13:43:15.061: W/System.err(25924): Slow frame!!! (12, g=9, w=2) 11-09 13:43:15.081: W/System.err(25924): Slow frame!!! (13, g=3, w=10) 11-09 13:43:15.111: W/System.err(25924): Slow frame!!! (23, g=16, w=6) 11-09 13:43:15.461: W/System.err(25924): Avg draw time: 5 11-09 13:43:16.142: W/System.err(25924): Slow frame!!! (18, g=3, w=15) 11-09 13:43:16.162: W/System.err(25924): Slow frame!!! (14, g=11, w=3) 11-09 13:43:16.482: W/System.err(25924): Avg draw time: 5 11-09 13:43:17.223: W/System.err(25924): Slow frame!!! (17, g=14, w=3) 11-09 13:43:17.243: W/System.err(25924): Slow frame!!! (15, g=4, w=11) 11-09 13:43:17.503: W/System.err(25924): Avg draw time: 5 11-09 13:43:18.054: W/System.err(25924): Slow frame!!! (17, g=9, w=8)