android - Stopped Service is Doing Constant Garbage Collection

Question

I am developing an application which has many services. When I stop the intent service, all threads and service should be stopped but the UI is hung and the following errors are in logcat:

2014-12-01 12: 37: 92I/art     (32099): Background partial concurrent mark sweep GC freed 419756(33MB) AllocSpace objects, 15(4MB) LOS objects, 38% free, 25MB/41MB, paused 1.617ms total 451.976ms
2014-12-01 12: 37: 40I/art     (32099): Background sticky concurrent mark sweep GC freed 290680(16MB) AllocSpace objects, 0(0B) LOS objects, 23% free, 25MB/33MB, paused 23.287ms total 229.513ms
2014-12-01 12: 37: 29I/art     (32099): Background partial concurrent mark sweep GC freed 165880(9MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 23MB/39MB, paused 1.648ms total 203.601ms
2014-12-01 12: 37: 54I/art     (32099): Background sticky concurrent mark sweep GC freed 269770(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 2.533ms total 207.538ms
2014-12-01 12: 37: 54I/art     (32099): WaitForGcToComplete blocked for 170.151ms for cause HeapTrim
2014-12-01 12: 37: 22I/art     (32099): Background partial concurrent mark sweep GC freed 155347(8MB) AllocSpace objects, 0(0B) LOS objects, 40% free, 23MB/39MB, paused 1.464ms total 181.474ms
2014-12-01 12: 38: 45I/art     (32099): Background sticky concurrent mark sweep GC freed 267766(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.556ms total 149.855ms
2014-12-01 12: 38: 11I/art     (32099): Background sticky concurrent mark sweep GC freed 137696(7MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.617ms total 125.255ms
2014-12-01 12: 38: 82I/art     (32099): Background partial concurrent mark sweep GC freed 148859(8MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 23MB/39MB, paused 1.373ms total 216.542ms
2014-12-01 12: 38: 11I/art     (32099): Background sticky concurrent mark sweep GC freed 276636(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.403ms total 156.661ms
2014-12-01 12: 38: 97I/art     (32099): Background sticky concurrent mark sweep GC freed 139573(7MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.464ms total 115.336ms
2014-12-01 12: 38: 85I/art     (32099): Background partial concurrent mark sweep GC freed 151267(8MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 23MB/39MB, paused 2.227ms total 210.346ms
2014-12-01 12: 38: 44I/art     (32099): Background sticky concurrent mark sweep GC freed 268102(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.495ms total 148.542ms
2014-12-01 12: 38: 27I/art     (32099): Background sticky concurrent mark sweep GC freed 137761(7MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.587ms total 119.121ms
2014-12-01 12: 38: 26I/art     (32099): Background partial concurrent mark sweep GC freed 154492(9MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 23MB/39MB, paused 2.533ms total 314.939ms
2014-12-01 12: 38: 75I/art     (32099): Thread[5,tid=32108,WaitingInMainSignalCatcherLoop,Thread*=0xb8111d98,peer=0x12c07080,"Signal Catcher"]: reacting to signal 3
2014-12-01 12: 38: 79W/art     (32099): Suspending all threads took: 13.062ms
2014-12-01 12: 38: 80I/art     (32099): Wrote stack traces to '/data/anr/traces.txt'
2014-12-01 12: 38: 89I/art     (32099): Background sticky concurrent mark sweep GC freed 278516(15MB) AllocSpace objects, 0(0B) LOS objects, 25% free, 23MB/31MB, paused 2.533ms total 1.049s
2014-12-01 12: 38: 13I/art     (32099): Background partial concurrent mark sweep GC freed 137132(8MB) AllocSpace objects, 0(0B) LOS objects, 40% free, 23MB/39MB, paused 4.211ms total 188.951ms
2014-12-01 12: 38: 42I/art     (32099): Background sticky concurrent mark sweep GC freed 271335(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 3.998ms total 236.868ms
2014-12-01 12: 38: 41I/art     (32099): Background sticky concurrent mark sweep GC freed 143812(8MB) AllocSpace objects, 0(0B) LOS objects, 23% free, 24MB/32MB, paused 6.470ms total 201.800ms
2014-12-01 12: 38: 36I/art     (32099): Background partial concurrent mark sweep GC freed 159223(9MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 23MB/39MB, paused 5.524ms total 215.809ms
2014-12-01 12: 38: 61I/art     (32099): Background sticky concurrent mark sweep GC freed 278158(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.922ms total 201.617ms
2014-12-01 12: 38: 41I/art     (32099): WaitForGcToComplete blocked for 46.696ms for cause HeapTrim
2014-12-01 12: 38: 79I/art     (32099): Background sticky concurrent mark sweep GC freed 136821(7MB) AllocSpace objects, 0(0B) LOS objects, 23% free, 24MB/32MB, paused 1.709ms total 123.729ms
2014-12-01 12: 38: 30I/art     (32099): Background sticky concurrent mark sweep GC freed 116947(6MB) AllocSpace objects, 0(0B) LOS objects, 20% free, 25MB/32MB, paused 5.554ms total 138.501ms
2014-12-01 12: 38: 44I/art     (32099): Background sticky concurrent mark sweep GC freed 117175(6MB) AllocSpace objects, 0(0B) LOS objects, 19% free, 25MB/32MB, paused 1.678ms total 104.257ms
2014-12-01 12: 38: 19I/art     (32099): Background sticky concurrent mark sweep GC freed 110760(6MB) AllocSpace objects, 0(0B) LOS objects, 18% free, 26MB/32MB, paused 1.587ms total 104.959ms
2014-12-01 12: 39: 37I/art     (32099): Background sticky concurrent mark sweep GC freed 88168(4MB) AllocSpace objects, 0(0B) LOS objects, 15% free, 27MB/32MB, paused 3.876ms total 114.878ms
2014-12-01 12: 39: 54I/art     (32099): Background partial concurrent mark sweep GC freed 136364(8MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 23MB/39MB, paused 1.648ms total 102.212ms
2014-12-01 12: 39: 60I/art     (32099): Background sticky concurrent mark sweep GC freed 287788(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 3.418ms total 196.154ms
2014-12-01 12: 39: 80I/art     (32099): Background sticky concurrent mark sweep GC freed 156308(8MB) AllocSpace objects, 0(0B) LOS objects, 25% free, 23MB/31MB, paused 3.998ms total 184.495ms
2014-12-01 12: 39: 33I/art     (32099): Background partial concurrent mark sweep GC freed 148206(8MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 23MB/39MB, paused 1.831ms total 103.738ms
2014-12-01 12: 39: 59I/art     (32099): Background sticky concurrent mark sweep GC freed 283901(15MB) AllocSpace objects, 0(0B) LOS objects, 25% free, 23MB/31MB, paused 2.502ms total 144.086ms
2014-12-01 12: 39: 43I/art     (32099): Background sticky concurrent mark sweep GC freed 134828(7MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/31MB, paused 2.533ms total 130.291ms
2014-12-01 12: 39: 44I/art     (32099): WaitForGcToComplete blocked for 94.277ms for cause HeapTrim
2014-12-01 12: 39: 95I/art     (32099): Background sticky concurrent mark sweep GC freed 133441(7MB) AllocSpace objects, 0(0B) LOS objects, 23% free, 24MB/31MB, paused 5.035ms total 139.722ms
2014-12-01 12: 39: 47I/art     (32099): Background partial concurrent mark sweep GC freed 148395(8MB) AllocSpace objects, 0(0B) LOS objects, 40% free, 23MB/39MB, paused 2.227ms total 122.722ms
2014-12-01 12: 39: 79I/art     (32099): Background sticky concurrent mark sweep GC freed 280706(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.495ms total 175.156ms
2014-12-01 12: 39: 44I/art     (32099): Background sticky concurrent mark sweep GC freed 144094(8MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 2.258ms total 140.119ms
2014-12-01 12: 39: 06I/art     (32099): Background partial concurrent mark sweep GC freed 152123(8MB) AllocSpace objects, 0(0B) LOS objects, 40% free, 23MB/39MB, paused 1.892ms total 108.957ms
2014-12-01 12: 39: 99I/art     (32099): Background sticky concurrent mark sweep GC freed 281291(15MB) AllocSpace objects, 0(0B) LOS objects, 25% free, 23MB/31MB, paused 6.104ms total 201.190ms
2014-12-01 12: 39: 02I/art     (32099): Background sticky concurrent mark sweep GC freed 136650(7MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/31MB, paused 41.049ms total 120.372ms
2014-12-01 12: 39: 56I/art     (32099): Background sticky concurrent mark sweep GC freed 134333(7MB) AllocSpace objects, 0(0B) LOS objects, 23% free, 24MB/31MB, paused 1.831ms total 130.260ms
2014-12-01 12: 39: 15I/art     (32099): Background partial concurrent mark sweep GC freed 145994(8MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 24MB/40MB, paused 1.800ms total 302.243ms
2014-12-01 12: 39: 49I/art     (32099): Background sticky concurrent mark sweep GC freed 285630(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 2.716ms total 235.434ms
2014-12-01 12: 39: 30I/art     (32099): Background sticky concurrent mark sweep GC freed 147718(8MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 3.845ms total 176.560ms
2014-12-01 12: 39: 94I/art     (32099): Background partial concurrent mark sweep GC freed 157542(9MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 23MB/39MB, paused 1.831ms total 178.879ms
2014-12-01 12: 39: 39I/art     (32099): Background sticky concurrent mark sweep GC freed 278485(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.495ms total 219.105ms
2014-12-01 12: 39: 90I/art     (32099): Background sticky concurrent mark sweep GC freed 147110(8MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.495ms total 143.293ms
2014-12-01 12: 39: 44I/art     (32099): Background sticky concurrent mark sweep GC freed 139322(7MB) AllocSpace objects, 0(0B) LOS objects, 23% free, 24MB/32MB, paused 2.197ms total 171.036ms
2014-12-01 12: 39: 10I/art     (32099): Background partial concurrent mark sweep GC freed 155748(9MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 24MB/40MB, paused 4.455ms total 268.915ms
2014-12-01 12: 39: 06I/art     (32099): Background sticky concurrent mark sweep GC freed 283584(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.770ms total 226.094ms
2014-12-01 12: 39: 13I/art     (32099): Background sticky concurrent mark sweep GC freed 14809(850KB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 5.920ms total 63.573ms
2014-12-01 12: 40: 05I/art     (32099): Background partial concurrent mark sweep GC freed 149252(8MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 23MB/39MB, paused 1.556ms total 177.445ms
2014-12-01 12: 40: 74I/art     (32099): Background sticky concurrent mark sweep GC freed 277718(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 3.631ms total 164.901ms
2014-12-01 12: 40: 29I/art     (32099): Background sticky concurrent mark sweep GC freed 144490(8MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 1.464ms total 134.198ms
2014-12-01 12: 40: 81I/art     (32099): Background sticky concurrent mark sweep GC freed 139991(7MB) AllocSpace objects, 0(0B) LOS objects, 23% free, 24MB/32MB, paused 1.709ms total 127.941ms
2014-12-01 12: 40: 38I/art     (32099): Background sticky concurrent mark sweep GC freed 135726(7MB) AllocSpace objects, 0(0B) LOS objects, 22% free, 25MB/32MB, paused 1.495ms total 168.411ms
2014-12-01 12: 40: 86I/art     (32099): Background partial concurrent mark sweep GC freed 155118(9MB) AllocSpace objects, 0(0B) LOS objects, 39% free, 23MB/39MB, paused 1.403ms total 217.701ms
2014-12-01 12: 40: 10I/art     (32099): Background sticky concurrent mark sweep GC freed 277621(15MB) AllocSpace objects, 0(0B) LOS objects, 24% free, 24MB/32MB, paused 5.035ms total 199.694ms
2014-12-01 12: 40: 91I/art     (32099): Background sticky concurrent mark sweep GC freed 137844(7MB) AllocSpace objects, 0(0B) LOS objects, 23% free, 24MB/32MB, paused 1.342ms total 137.830ms
2014-12-01 12: 40: 51I/art     (32099): Background sticky concurrent mark sweep GC freed 133133(7MB

Answer 1

Profile your app - I found the cause of my similar problem that way.

Android Studio: Tools -> Android -> Android Device Monitor

Select your app and it the top (left) select:

Start method profiling

and after some time stop it the see the result.