Monday 19 March 2018

Android Dalvik and ART GC(Garbage Collection) logs Analysis


Hello Guys!!! Hope you all are doing well.!!!!!!
Today I am going to discuss GC logs analysis in android. In my previous blog we have discuss android general log analysis. But today topic is concentrated on GC log analysis.
Memory utilization in Android device(let say mobile phone device) is utterly important topic from the beginning of time. Now a day We have high end mobile phone with much memory(RAM) compare to initial day. But still Memory utilization on the mobile app has a significant impact on the customer experience.
Let assume If any app creates a lot of objects during uses, then Garbage Collection (GC) process will be triggered frequently to evict unused objects. As we know Garbage Collection is an automatic process in Android/Java to free-up unused memory, however, frequent Garbage Collection consumes a lot of CPU + it will also pause the app. Frequent pauses can junk the app (i.e. stuttering, juddering, or halting).
Whenever a GC event runs, a log line is printed in the run-time log messages. So by closely monitoring run-time logs or say collected logs file we can understand how many objects by an app is creating, how frequently Garbage collection is triggered, how much time it takes to complete, how much memory is reclaimed after every event.
GC log line format varies based on whether app runs on Dalvik VM or Android Run Time (ART).This is how a typical ART GC log line will look:-
1                                                                                                                 3

07-01 16:00:44.690: I/art(801): Explicit concurrent mark sweep GC freed 65595(3MB) 
                                     4                                                      5                                    6
AllocSpace objects, 9(4MB) LOS objects, 34% free, 38MB/58MB, paused 1.195ms total 
    7
87.219ms

#
Field
Value
Description
1
Timestamp
07-01 16:00:44.690
Timestamp at which this Garbage Collection event ran
2
GC Reason
Explicit
Reason why Garbage Collection event was triggered.‘Explicit’ indicates that garbage collection was explicitly requested by an app, for example, by calling gc() or gc(). Please refer Below for different types of GC Reasons.
3
GC Name
concurrent mark sweep
ART has various different GCs which can get run. In this case, ‘Concurrent Mark Sweep’ indicates – a whole heap collector which frees collects all spaces other than the image space.  Please refer below for different types of GC Names.
4
Objects freed
65595(3MB)
Amount of objects garbage collected from non-large objects space. Totally 65595 unique objects, whose cumulative size of 3mb is garbage collected (i.e. freed) in this event.
5
Large objects freed
9(4MB)
Amount of objects garbage collected from Large objects space. Totally 9 unique objects, whose cumulative size of 4mb is garbage collected (i.e. freed)
6
Heap usage
38MB/58MB
38mb of objects is alive after this particular GC event. Total allocated heap size for this application is 58mb.
7
GC Pause Time
1.195ms
During certain phases of GC event, the application is paused. In this GC event, pause time is 1.195ms. During pause time, application freezes. One should target for low pause time.
8
GC Total Time
87.219ms
Amount of time this GC event took to complete. It includes the GC Pause time as well.
GC Reason
What triggered the GC and what kind of collection it is.
Concurrent
A concurrent GC that does not suspend app threads. This GC runs in a background thread and does not prevent allocations.
Alloc
The GC was initiated because your app attempted to allocate memory when your heap was already full. In this case, the garbage collection occurred in the allocating thread.
Explicit
The garbage collection was explicitly requested by an app, for example, by calling gc() or gc(). Like Dalvik, in ART the best practice is that you trust the GC and avoid requesting explicit GCs, if possible. Explicit GCs are discouraged because they block the allocating thread and unnecessarily waste CPU cycles. Explicit GCs could also cause jank (stuttering, juddering, or halting in the app) if they cause other threads to get preempted.
NativeAlloc
The collection was caused by native memory pressure from native allocations such as Bitmaps or RenderScript allocation objects.
CollectorTransition
The collection was caused by a heap transition; this is caused by changing the GC strategy at run time (such as when the app changes between pause perceptible states). Collector transitions consist of copying all the objects from a free-list backed space to a bump pointer space (or visa versa).
This occurs only on low RAM device prior to Android 8.0 when an app changes process states from a pause perceptible state (such as when the app is in the foreground, where the user can preceive a GC pause) to a non pause perceptible state (or visa versa).
HomogeneousSpaceCompact
Homogeneous space compaction is free-list space to free-list space compaction which usually occurs when an app is moved to a pause imperceptible process state. The main reasons for doing this are reducing RAM usage and defragmenting the heap.
DisableMovingGc
This is not a real GC reason, but a note that collection was blocked due to use of GetPrimitiveArrayCritical. while concurrent heap compaction is occurring. In general, the use of GetPrimitiveArrayCritical is strongly discouraged due to its restrictions on moving collectors.
HeapTrim
This is not a GC reason, but a note that collection was blocked until a heap trim finished.

GC Name
ART has various different GCs which can get run.
Concurrent mark sweep (CMS)
A whole heap collector which frees collects all spaces other than the image space.
Concurrent partial mark sweep
A mostly whole heap collector which collects all spaces other than the image and zygote spaces.
Concurrent sticky mark sweep
A generational collector which can only free objects allocated since the last GC. This garbage collection is run more often than a full or partial mark sweep since it is faster and has lower pauses.
Marksweep + semispace
A non concurrent, copying GC used for heap transitions as well as homogeneous space compaction (to defragement the heap).
Now We can discuss about Dalvik GC Log anlysis. 
This is how a typical Dalvik GC log line will look like:-
Dalvik-1







Below table summarizes each field in detail:

#
Field Value Description
1
Timestamp
07-01 15:56:19.815
Timestamp at which this Garbage Collection event ran
2
GC Reason
GC CONCURRENT
Reason why Garbage Collection event was triggered. Please refer below for different types of GC Reasons.
3
Objects freed
7078K
Amount of objects garbage collected. Totally 7078kb of objects are garbage collected (i.e. freed) in this event.
4
Heap usage
52464K/ 89052K
52464kb of objects are alive after this particular GC event. Total allocated heap size for this app is 89052 kb.
5
GC Pause Time
14ms+4ms
During certain phases of GC event, application is paused. In this GC event, pause time is 18 ms (i.e. 14 + 4 ms). During pause time, application freezes. One should target for low pause time.
6
GC Total Time
96ms
Amount of time this GC event took to complete. It includes the GC Pause time as well.
Dalvik GC Reason
What triggered the GC and what kind of collection it is. Reasons that might appear include:
GC_CONCURRENT
A concurrent GC that frees up memory as your heap begins to fill up.
GC_FOR_MALLOC
A GC was caused because your app attempted to allocate memory when your heap was already full, so the system had to stop your app and reclaim memory.
GC_HPROF_DUMP_HEAP
A GC that occurs when you request to create an HPROF file to analyze your heap.
GC_EXPLICIT
An explicit GC, such as when you call gc() (which you should avoid calling and instead trust the GC to run when needed).
GC_EXTERNAL_ALLOC
This happens only on API level 10 and lower (newer versions allocate everything in the Dalvik heap). A GC for externally allocated memory (such as the pixel data stored in native memory or NIO byte buffers)


As We all feel analyzing every single GC log line is very tedious work. So this is the obvious question "is there any tool for it ?" And the answer is Yes!!!!. We have few option:
  • Use Android Studio inbuilt tool
  • Use free online tools such as GCeasy.io
GCeasy.io – a universal Garbage collection log analyzer, to analyze Android GC logs. You can just upload the Android GC Logs to this tool. Tool parses GC log and generates report instantly. Report contains interactive graphs and insightful metrics.

So Hope this article address your Android GC log analysis understanding better. Please provide your feedback in  blog comment box.

Thanks
Saurabh
Happy Coding!!!!

22 comments:

  1. Descargar Lucky Patcher Apk can hack many games easily with the Lucky Patcher tool. Modify many apps and games with this free to use tool

    ReplyDelete
  2. Good article! About analyzing Android GC logs, GCeasy is also good. It is free web tool. You have to upload your GC logs to their server, and results are provided online

    ReplyDelete
  3. Great piece of information. Very informative. No need to look elsewhere. I read it and get knowledge deeply. I learn so much new thing from here.
    mobile apps agencies in india

    ReplyDelete
  4. Thanks for sharing the useful blog about analyzing Garbage Collection logs in Android.

    Android App Development Companies in Coimbatore

    ReplyDelete
  5. your article is valuable for me and for others. Thanks for sharing your information!
    CSIR NET JRF MATHEMATICS RESULT

    ReplyDelete
  6. Good work.
    Do you want to sign up bigo live app?
    bigo live app signup

    ReplyDelete
  7. I really liked the way you are delivering the content. I am just waiting for more updates from your site. Kindly keep sharing more of this kind.

    Spoken English Classes in Chennai
    IELTS Coaching in Chennai
    Best Spoken English Classes in Chennai
    Spoken English Class in Chennai
    Spoken English in Chennai
    English Classes in Chennai

    ReplyDelete
  8. This comment has been removed by the author.

    ReplyDelete
  9. Your article is just amazing.You might be interested in:subway surfers money

    ReplyDelete
  10. I Love your article. You can visit my website : subway surfer save file

    ReplyDelete
  11. Good to become visiting your weblog again, it has been months for me. Nicely this article that i've been waited for so long. I will need this post to total my assignment in the college, and it has exact same topic together with your write-up. Thanks, good share. TubeMate 3 APK Download Free Latest Version

    ReplyDelete
  12. digital marketing executive interview questions and answers for freshers

    Important Digital Marketing Interview Questions and Answers for freshers and experienced to get your dream job in Digital Marketing! Basic Digital Marketing Interview Questions for Freshers.Interview questions on digital marketing

    ReplyDelete
  13. aws interview questions and answers for devops

    Important DevOps Interview Questions and Answers for freshers and experienced to start your career in DevOps! 101 DevOps Basic Interview Questions for Freshers.devops interview questions and answers for experienced

    ReplyDelete
  14. Great piece of information. Very informative. No need to look elsewhere. I read it and get knowledge deeply. I learn so much new thing from here.
    Web development Company in Varanasi India
    APP development Company in Varanasi India

    ReplyDelete

Build a Custom Kernel Module for Android

Hi Guys!!!Hope you are doing well !!!. Today I will describe how you can write a custom kernel module(Hello world) for Android and load it a...