3 # Copyright (C) 2009 The Android Open Source Project
5 # Licensed under the Apache License, Version 2.0 (the "License");
6 # you may not use this file except in compliance with the License.
7 # You may obtain a copy of the License at
9 # http://www.apache.org/licenses/LICENSE-2.0
11 # Unless required by applicable law or agreed to in writing, software
12 # distributed under the License is distributed on an "AS IS" BASIS,
13 # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14 # See the License for the specific language governing permissions and
15 # limitations under the License.
18 # Parse event log output, looking for GC events. Format them for human
21 # ALL OUTPUT VALUES ARE APPROXIMATE. The event log data format uses a
22 # 12-bit floating-point representation, which means there aren't enough
23 # bits to accurately represent anything but small integers. Larger
24 # values will be rounded off.
26 # The data is generated by dalvik/vm/alloc/HeapDebug.c.
35 DEBUG = False # DEBUG is a global variable
39 """Unpack a float12 value"""
41 raise DataParseError, "bad float12 value %s" % f12
42 return (f12 & 0x1ff) << ((f12 >> 9) * 4)
45 def parseGlobalInfo(value):
46 """Parse event0 (global info)"""
52 # [62-24] ASCII process identifier
53 # [23-12] GC time in ms
55 id = (value >> 24) & 0xffffffffff
56 gctime = unfloat12((value >> 12) & 0xfff)
57 bytes_freed = unfloat12(value & 0xfff)
59 idstr = "%c%c%c%c%c" % ( \
66 return ( idstr, gctime, bytes_freed )
69 def parseAggHeapStats(value):
70 """Parse event1 (aggregated heap stats)"""
73 # Aggregated heap stats:
76 # [61-60] Reserved; must be zero
77 # [59-48] Objects freed
78 # [47-36] Actual size (current footprint)
79 # [35-24] Allowed size (current hard max)
80 # [23-12] Objects allocated
81 # [11- 0] Bytes allocated
82 freed = unfloat12((value >> 48) & 0xfff)
83 footprint = unfloat12((value >> 36) & 0xfff)
84 allowed = unfloat12((value >> 24) & 0xfff)
85 objs = unfloat12((value >> 12) & 0xfff)
86 bytes = unfloat12(value & 0xfff)
88 return ( freed, footprint, allowed, objs, bytes )
91 def parseZygoteStats(value):
92 """Parse event2 (zygote heap stats)"""
95 # Zygote heap stats (except for the soft limit, which belongs to the
99 # [61-60] Reserved; must be zero
100 # [59-48] Soft Limit (for the active heap)
101 # [47-36] Actual size (current footprint)
102 # [35-24] Allowed size (current hard max)
103 # [23-12] Objects allocated
104 # [11- 0] Bytes allocated
105 soft_limit = unfloat12((value >> 48) & 0xfff)
106 actual = unfloat12((value >> 36) & 0xfff)
107 allowed = unfloat12((value >> 24) & 0xfff)
108 objs = unfloat12((value >> 12) & 0xfff)
109 bytes = unfloat12(value & 0xfff)
111 return ( soft_limit, actual, allowed, objs, bytes )
114 def parseExternalStats(value):
115 """Parse event3 (external allocation stats)"""
118 # Report the current external allocation stats and the native heap
121 # [63-48] Reserved; must be zero (TODO: put new data in these slots)
122 # [47-36] dlmalloc_footprint
123 # [35-24] mallinfo: total allocated space
124 # [23-12] External byte limit
125 # [11- 0] External bytes allocated
126 footprint = unfloat12((value >> 36) & 0xfff) # currently disabled
127 total = unfloat12((value >> 24) & 0xfff) # currently disabled
128 limit = unfloat12((value >> 12) & 0xfff)
129 bytes = unfloat12(value & 0xfff)
131 return ( footprint, total, limit, bytes )
134 def handleGcInfo(procFilter, timestamp, pid, values):
135 """Handle a single dvm_gc_info event"""
139 global_info = parseGlobalInfo(values[0])
141 if len(procFilter) > 0:
142 if global_info[0] != procFilter:
145 heap_stats = parseAggHeapStats(values[1])
146 zygote = parseZygoteStats(values[2])
147 external = parseExternalStats(values[3])
149 print "%s %s(%d) softlim=%dKB, extlim=%dKB, extalloc=%dKB" % \
150 (timestamp, global_info[0], pid, zygote[0]/1024, external[2]/1024, external[3]/1024)
153 # print "RAW: %s %s (%s,%s,%s,%s)" % \
154 # (timestamp, pid, values[0], values[1], values[2], values[3])
156 print "+ id=\"%s\" time=%d freed=%d" % (global_info[0], global_info[1], global_info[2])
157 print "+ freed=%d foot=%d allow=%d objs=%d bytes=%d" % \
158 (heap_stats[0], heap_stats[1], heap_stats[2], heap_stats[3], heap_stats[4])
159 print "+ soft=%d act=%d allow=%d objs=%d bytes=%d" % \
160 (zygote[0], zygote[1], zygote[2], zygote[3], zygote[4])
161 print "+ foot=%d total=%d limit=%d alloc=%d" % \
162 (external[0], external[1], external[2], external[3])
164 print " freed %d objects / %d bytes in %dms" % \
165 (heap_stats[0], global_info[2], global_info[1])
168 def filterInput(logPipe, processFilter):
169 """Loop until EOF, pulling out GC events"""
171 # 04-29 20:31:00.334 I/dvm_gc_info( 69): [8320808730292729543,-8916699241518090181,-4006371297196337158,8165229]
172 gc_info_re = re.compile(r"""
173 (\d+-\d+\ \d+:\d+:\d+)\.\d+ # extract the date (#1), ignoring ms
174 .* # filler, usually " I/"
175 dvm_gc_info # only interested in GC info lines
176 \(\s*(\d+)\) # extract the pid (#2)
178 ([0-9-]+),([0-9-]+),([0-9-]+),([0-9-]+) # four values, may be negative
179 \].* # junk to end of line
183 line = logPipe.readline()
188 match = gc_info_re.match(line)
190 #print "no match on %s" % line.strip()
193 handleGcInfo(processFilter, match.group(1), match.group(2), ( match.group(3), \
194 match.group(4), match.group(5), match.group(6) ) )
197 print "usage: %s [-p procFilter] [-d]" % sys.argv[0]
207 opts, args = getopt.getopt(sys.argv[1:], "hdp:")
209 for opt, val in opts:
218 print "procfilter = %s" % procFilter
219 print "DEBUG = %s" % DEBUG
221 # launch a logcat and read from it
222 command = 'adb logcat -v time -b events'
223 logPipe = os.popen(command)
227 filterInput(logPipe, procFilter)
228 except KeyboardInterrupt, err:
229 print "Stopping on keyboard interrupt."