[Asterisk-code-review] refdebug: Create refstats.py script. (asterisk[master])
George Joseph
asteriskteam at digium.com
Tue Oct 16 13:43:07 CDT 2018
George Joseph has submitted this change and it was merged. ( https://gerrit.asterisk.org/10477 )
Change subject: refdebug: Create refstats.py script.
......................................................................
refdebug: Create refstats.py script.
This allows us to process AO2 statistics for total objects, memory
usage, memory overhead and lock usage.
* Install refstats.py and reflocks.py into the Asterisk scripts folder.
* Enable support for reflocks.py without DEBUG_THREADS.
Steal a bit from the ao2 magic to flag when an object lock is used.
Remove 'lockobj' from reflocks.py since we can now record 'used' or
'unused' for those objects.
Add comments to explain thread safety of the 'struct __priv_data'
bitfields.
Change-Id: I84e9d679cc86d772cc97c888d9d856a17e0d3a4a
---
M contrib/Makefile
M contrib/scripts/refcounter.py
M contrib/scripts/reflocks.py
A contrib/scripts/refstats.py
M main/astobj2.c
5 files changed, 243 insertions(+), 47 deletions(-)
Approvals:
Richard Mudgett: Looks good to me, but someone else must approve
George Joseph: Looks good to me, approved; Approved for Submit
diff --git a/contrib/Makefile b/contrib/Makefile
index 9512de5..074a12b 100644
--- a/contrib/Makefile
+++ b/contrib/Makefile
@@ -25,9 +25,13 @@
$(INSTALL) -m 755 scripts/ast_loggrabber "$(DESTDIR)$(ASTDATADIR)/scripts/ast_loggrabber"
$(INSTALL) -m 755 scripts/ast_coredumper "$(DESTDIR)$(ASTDATADIR)/scripts/ast_coredumper"
$(INSTALL) -m 755 scripts/refcounter.py "$(DESTDIR)$(ASTDATADIR)/scripts/refcounter.py"
+ $(INSTALL) -m 755 scripts/refstats.py "$(DESTDIR)$(ASTDATADIR)/scripts/refstats.py"
+ $(INSTALL) -m 755 scripts/reflocks.py "$(DESTDIR)$(ASTDATADIR)/scripts/reflocks.py"
uninstall:
-rm -f "$(DESTDIR)$(ASTDATADIR)/scripts/ast_logescalator"
-rm -f "$(DESTDIR)$(ASTDATADIR)/scripts/ast_loggrabber"
-rm -f "$(DESTDIR)$(ASTDATADIR)/scripts/ast_coredumper"
-rm -f "$(DESTDIR)$(ASTDATADIR)/scripts/refcounter.py"
+ -rm -f "$(DESTDIR)$(ASTDATADIR)/scripts/refstats.py"
+ -rm -f "$(DESTDIR)$(ASTDATADIR)/scripts/reflocks.py"
diff --git a/contrib/scripts/refcounter.py b/contrib/scripts/refcounter.py
index 36fb341..146a024 100755
--- a/contrib/scripts/refcounter.py
+++ b/contrib/scripts/refcounter.py
@@ -108,8 +108,10 @@
else:
current_objects[obj]['curcount'] += int(parsed_line['delta'])
- if 'destructor' in parsed_line['state']:
- # refcounter.py doesn't care about lock-state.
+ # Suppress object sizes and lock-state from output logs.
+ if 'constructor' in parsed_line['state']:
+ parsed_line['state'] = '**constructor**'
+ elif 'destructor' in parsed_line['state']:
parsed_line['state'] = '**destructor**'
current_objects[obj]['log'].append(
diff --git a/contrib/scripts/reflocks.py b/contrib/scripts/reflocks.py
index 7d8edfc..db1985f 100755
--- a/contrib/scripts/reflocks.py
+++ b/contrib/scripts/reflocks.py
@@ -48,7 +48,6 @@
object_types[obj_type] = {
'used': 0,
'unused': 0,
- 'lockobj': 0,
'none': 0
}
objects[addr] = obj_type
@@ -62,8 +61,6 @@
object_types[obj_type]['unused'] += 1
elif '**lock-state:used**' in state:
object_types[obj_type]['used'] += 1
- elif '**lock-state:lockobj**' in state:
- object_types[obj_type]['lockobj'] += 1
elif '**lock-state:none**' in state:
object_types[obj_type]['none'] += 1
@@ -75,8 +72,6 @@
stats.append("%d used" % info['used'])
if info['unused'] > 0:
stats.append("%d unused" % info['unused'])
- if info['lockobj'] > 0 and options.lockobj:
- stats.append("%d lockobj" % info['lockobj'])
if info['none'] > 0 and options.none:
stats.append("%d none" % info['none'])
if len(stats) == 0:
@@ -103,9 +98,6 @@
parser.add_option("-n", "--show-none", action="store_true",
dest="none", default=False,
help="Show counts of objects with no locking.")
- parser.add_option("-o", "--show-lockobj", action="store_true",
- dest="lockobj", default=False,
- help="Show counts of objects with a lockobj.")
(options, args) = parser.parse_args(argv)
diff --git a/contrib/scripts/refstats.py b/contrib/scripts/refstats.py
new file mode 100755
index 0000000..93df02f
--- /dev/null
+++ b/contrib/scripts/refstats.py
@@ -0,0 +1,180 @@
+#!/usr/bin/env python
+"""Process a ref debug log for memory usage
+
+ This will provide information about total and peak
+ allocations.
+
+ See http://www.asterisk.org for more information about
+ the Asterisk project. Please do not directly contact
+ any of the maintainers of this project for assistance;
+ the project provides a web site, mailing lists and IRC
+ channels for your use.
+
+ This program is free software, distributed under the terms of
+ the GNU General Public License Version 2. See the LICENSE file
+ at the top of the source tree.
+
+ Copyright (C) 2018, CFWare, LLC
+ Corey Farrell <git at cfware.com>
+"""
+
+from __future__ import print_function
+import sys
+import os
+
+from optparse import OptionParser
+
+
+def create_stats():
+ """Create statistics object"""
+ return {
+ 'count': 0,
+ 'overhead': 0,
+ 'user_data': 0,
+ 'totalmem': 0
+ }
+
+
+def update_stats(current, peak, total, key, direction, delta):
+ """Update statistics objects"""
+
+ if direction == 1:
+ total[key] += delta
+
+ delta *= direction
+ current[key] += delta
+ if current[key] > peak[key]:
+ peak[key] = current[key]
+
+
+def process_file(options):
+ """The routine that kicks off processing a ref file"""
+
+ current = create_stats()
+ total = create_stats()
+ peak = create_stats()
+ object_types = {}
+ objects = {}
+ filename = options.filepath
+
+ with open(filename, 'r') as ref_file:
+ for line in ref_file:
+ if 'constructor' not in line and 'destructor' not in line:
+ continue
+ # The line format is:
+ # addr,delta,thread_id,file,line,function,state,tag
+ # Only addr, file, line, function, state are used by reflocks.py
+ tokens = line.strip().split(',', 7)
+ addr = tokens[0]
+ state = tokens[6]
+ if 'constructor' in state:
+ split_state = state.split("**")
+ if len(split_state) < 4:
+ print("File does not contain object size information", file=sys.stderr)
+ sys.exit(1)
+
+ obj_type = '%s:%s:%s' % (tokens[3], tokens[4], tokens[5])
+ if obj_type not in object_types:
+ object_types[obj_type] = {
+ 'used': 0,
+ 'unused': 0,
+ 'none': 0
+ }
+ overhead = int(split_state[2])
+ user_data = int(split_state[3])
+ obj = objects[addr] = {
+ 'overhead': overhead,
+ 'user_data': user_data,
+ 'obj_type': obj_type
+ }
+
+ direction = 1
+ else:
+ if addr not in objects:
+ # This error would be reported by refcounter.py.
+ continue
+ obj = objects[addr]
+ del objects[addr]
+ direction = -1
+ obj_type = obj['obj_type']
+ if '**lock-state:unused**' in state:
+ object_types[obj_type]['unused'] += 1
+ elif '**lock-state:used**' in state:
+ object_types[obj_type]['used'] += 1
+
+ # Increment current and peak usage
+ update_stats(current, peak, total, 'count', direction, 1)
+ update_stats(current, peak, total, 'overhead', direction, obj['overhead'])
+ update_stats(current, peak, total, 'user_data', direction, obj['user_data'])
+ update_stats(current, peak, total, 'totalmem', direction, obj['overhead'] + obj['user_data'])
+
+ print("Total usage statistics:")
+ print("%20s: %d" % ("Count", total['count']))
+ print("%20s: %d" % ("Total Memory (k)", total['totalmem'] / 1024))
+ print("%20s: %d (%.2f%%)" % ("Overhead (k)", total['overhead'] / 1024, total['overhead'] * 100.0 / total['totalmem']))
+ print("%20s: %d" % ("User Data (k)", total['user_data'] / 1024))
+ print("")
+ print("Peak usage statistics:")
+ print("%20s: %d" % ("Count", peak['count']))
+ print("%20s: %d" % ("Total Memory (k)", peak['totalmem'] / 1024))
+ print("%20s: %d (%.2f%%)" % ("Overhead (k)", peak['overhead'] / 1024, peak['overhead'] * 100.0 / peak['totalmem']))
+ print("%20s: %d" % ("User Data (k)", peak['user_data'] / 1024))
+ print("")
+
+ lockbyobj = {'used': 0, 'total': 0}
+ lockbytype = {'used': 0, 'total': 0}
+ for (allocator, info) in object_types.items():
+ lockbyobj['used'] += info['used']
+ lockbyobj['total'] += info['used'] + info['unused']
+
+ if info['used'] != 0:
+ lockbytype['used'] += 1
+ elif info['unused'] == 0:
+ # This object type doesn't have locking.
+ continue
+ lockbytype['total'] += 1
+
+ print("Lock usage statistics:")
+ print("%20s: %d of %d used (%.2f%%)" % (
+ "By object",
+ lockbyobj['used'],
+ lockbyobj['total'],
+ lockbyobj['used'] * 100.0 / lockbyobj['total']))
+ print("%20s: %d of %d used (%.2f%%)" % (
+ "By type",
+ lockbytype['used'],
+ lockbytype['total'],
+ lockbytype['used'] * 100.0 / lockbytype['total']))
+
+
+def main(argv=None):
+ """Main entry point for the script"""
+
+ ret_code = 0
+
+ if argv is None:
+ argv = sys.argv
+
+ parser = OptionParser()
+
+ parser.add_option("-f", "--file", action="store", type="string",
+ dest="filepath", default="/var/log/asterisk/refs",
+ help="The full path to the refs file to process")
+
+ (options, args) = parser.parse_args(argv)
+
+ if not os.path.isfile(options.filepath):
+ print("File not found: %s" % options.filepath, file=sys.stderr)
+ return -1
+
+ try:
+ process_file(options)
+ except (KeyboardInterrupt, SystemExit, IOError):
+ print("File processing cancelled", file=sys.stderr)
+ return -1
+
+ return ret_code
+
+
+if __name__ == "__main__":
+ sys.exit(main(sys.argv))
diff --git a/main/astobj2.c b/main/astobj2.c
index d6a8a4e..ebc0720 100644
--- a/main/astobj2.c
+++ b/main/astobj2.c
@@ -61,15 +61,40 @@
#endif
/*! Number of references held for this object */
int32_t ref_counter;
- /*! The ao2 object option flags */
+ /*!
+ * \brief The ao2 object option flags.
+ *
+ * \note This field is constant after object creation. It shares
+ * a uint32_t with \ref lockused and \ref magic.
+ */
uint32_t options:2;
- /*! magic number. This is used to verify that a pointer passed in is a
- * valid astobj2 or ao2_weak reference */
- uint32_t magic:30;
+ /*!
+ * \brief Set to 1 when the lock is used if refdebug is enabled.
+ *
+ * \note This bit-field may be modified after object creation. It
+ * shares a uint32_t with \ref options and \ref magic.
+ */
+ uint32_t lockused:1;
+ /*!
+ * \brief Magic number.
+ *
+ * This is used to verify that a pointer is a valid astobj2 or ao2_weak
+ * reference.
+ *
+ * \note This field is constant after object creation. It shares
+ * a uint32_t with \ref options and \ref lockused.
+ *
+ * \warning Stealing bits for any additional writable fields would cause
+ * reentrancy issues if using bitfields. If any additional
+ * writable bits are required in the future we will need to put
+ * all bitfields into a single 'uint32_t flags' field and use
+ * atomic operations from \file lock.h to perform writes.
+ */
+ uint32_t magic:29;
};
-#define AO2_MAGIC 0x3a70b123
-#define AO2_WEAK 0x3a70b122
+#define AO2_MAGIC 0x1a70b123
+#define AO2_WEAK 0x1a70b122
#define IS_AO2_MAGIC_BAD(p) (AO2_MAGIC != (p->priv_data.magic | 1))
/*!
@@ -206,6 +231,10 @@
return -1;
}
+ if (ref_log) {
+ obj->priv_data.lockused = 1;
+ }
+
switch (obj->priv_data.options & AO2_ALLOC_OPT_LOCK_MASK) {
case AO2_ALLOC_OPT_LOCK_MUTEX:
obj_mutex = INTERNAL_OBJ_MUTEX(user_data);
@@ -322,6 +351,10 @@
return -1;
}
+ if (ref_log) {
+ obj->priv_data.lockused = 1;
+ }
+
switch (obj->priv_data.options & AO2_ALLOC_OPT_LOCK_MASK) {
case AO2_ALLOC_OPT_LOCK_MUTEX:
obj_mutex = INTERNAL_OBJ_MUTEX(user_data);
@@ -369,7 +402,6 @@
return -1;
}
-
return res;
}
@@ -473,9 +505,7 @@
int32_t current_value;
int32_t ret;
struct ao2_weakproxy *weakproxy = NULL;
-#ifdef DEBUG_THREADS
const char *lock_state;
-#endif
if (obj == NULL) {
if (ref_log && user_data) {
@@ -595,33 +625,25 @@
switch (obj->priv_data.options & AO2_ALLOC_OPT_LOCK_MASK) {
case AO2_ALLOC_OPT_LOCK_MUTEX:
obj_mutex = INTERNAL_OBJ_MUTEX(user_data);
-#ifdef DEBUG_THREADS
- lock_state = obj_mutex->mutex.lock.flags.setup ? "used" : "unused";
-#endif
+ lock_state = obj->priv_data.lockused ? "used" : "unused";
ast_mutex_destroy(&obj_mutex->mutex.lock);
ast_free(obj_mutex);
break;
case AO2_ALLOC_OPT_LOCK_RWLOCK:
obj_rwlock = INTERNAL_OBJ_RWLOCK(user_data);
-#ifdef DEBUG_THREADS
- lock_state = obj_rwlock->rwlock.lock.flags.setup ? "used" : "unused";
-#endif
+ lock_state = obj->priv_data.lockused ? "used" : "unused";
ast_rwlock_destroy(&obj_rwlock->rwlock.lock);
ast_free(obj_rwlock);
break;
case AO2_ALLOC_OPT_LOCK_NOLOCK:
-#ifdef DEBUG_THREADS
lock_state = "none";
-#endif
ast_free(obj);
break;
case AO2_ALLOC_OPT_LOCK_OBJ:
obj_lockobj = INTERNAL_OBJ_LOCKOBJ(user_data);
-#ifdef DEBUG_THREADS
- lock_state = "lockobj";
-#endif
+ lock_state = obj->priv_data.lockused ? "used" : "unused";
ao2_t_ref(obj_lockobj->lockobj.lock, -1, "release lockobj");
ast_free(obj_lockobj);
@@ -629,22 +651,13 @@
default:
ast_log(__LOG_ERROR, file, line, func,
"Invalid lock option on ao2 object %p\n", user_data);
-#ifdef DEBUG_THREADS
lock_state = "invalid";
-#endif
break;
}
if (ref_log && tag) {
- fprintf(ref_log, "%p,%d,%d,%s,%d,%s,**destructor%s%s**,%s\n",
- user_data, delta, ast_get_tid(), file, line, func,
-#ifdef DEBUG_THREADS
- "**lock-state:",
- lock_state,
-#else
- "", "",
-#endif
- tag);
+ fprintf(ref_log, "%p,%d,%d,%s,%d,%s,**destructor**lock-state:%s**,%s\n",
+ user_data, delta, ast_get_tid(), file, line, func, lock_state, tag);
fflush(ref_log);
}
@@ -673,10 +686,12 @@
struct astobj2_lock *obj_mutex;
struct astobj2_rwlock *obj_rwlock;
struct astobj2_lockobj *obj_lockobj;
+ size_t overhead;
switch (options & AO2_ALLOC_OPT_LOCK_MASK) {
case AO2_ALLOC_OPT_LOCK_MUTEX:
- obj_mutex = __ast_calloc(1, sizeof(*obj_mutex) + data_size, file, line, func);
+ overhead = sizeof(*obj_mutex);
+ obj_mutex = __ast_calloc(1, overhead + data_size, file, line, func);
if (obj_mutex == NULL) {
return NULL;
}
@@ -685,7 +700,8 @@
obj = (struct astobj2 *) &obj_mutex->priv_data;
break;
case AO2_ALLOC_OPT_LOCK_RWLOCK:
- obj_rwlock = __ast_calloc(1, sizeof(*obj_rwlock) + data_size, file, line, func);
+ overhead = sizeof(*obj_rwlock);
+ obj_rwlock = __ast_calloc(1, overhead + data_size, file, line, func);
if (obj_rwlock == NULL) {
return NULL;
}
@@ -694,7 +710,8 @@
obj = (struct astobj2 *) &obj_rwlock->priv_data;
break;
case AO2_ALLOC_OPT_LOCK_NOLOCK:
- obj = __ast_calloc(1, sizeof(*obj) + data_size, file, line, func);
+ overhead = sizeof(*obj);
+ obj = __ast_calloc(1, overhead + data_size, file, line, func);
if (obj == NULL) {
return NULL;
}
@@ -706,7 +723,8 @@
return NULL;
}
- obj_lockobj = __ast_calloc(1, sizeof(*obj_lockobj) + data_size, file, line, func);
+ overhead = sizeof(*obj_lockobj);
+ obj_lockobj = __ast_calloc(1, overhead + data_size, file, line, func);
if (obj_lockobj == NULL) {
ao2_t_ref(lockobj, -1, "release lockobj for failed alloc");
return NULL;
@@ -735,8 +753,8 @@
#endif
if (ref_log && tag) {
- fprintf(ref_log, "%p,+1,%d,%s,%d,%s,**constructor**,%s\n",
- EXTERNAL_OBJ(obj), ast_get_tid(), file, line, func, tag);
+ fprintf(ref_log, "%p,+1,%d,%s,%d,%s,**constructor**%zu**%zu**,%s\n",
+ EXTERNAL_OBJ(obj), ast_get_tid(), file, line, func, overhead, data_size, tag);
fflush(ref_log);
}
--
To view, visit https://gerrit.asterisk.org/10477
To unsubscribe, or for help writing mail filters, visit https://gerrit.asterisk.org/settings
Gerrit-Project: asterisk
Gerrit-Branch: master
Gerrit-MessageType: merged
Gerrit-Change-Id: I84e9d679cc86d772cc97c888d9d856a17e0d3a4a
Gerrit-Change-Number: 10477
Gerrit-PatchSet: 2
Gerrit-Owner: Corey Farrell <git at cfware.com>
Gerrit-Reviewer: George Joseph <gjoseph at digium.com>
Gerrit-Reviewer: Jenkins2 (1000185)
Gerrit-Reviewer: Richard Mudgett <rmudgett at digium.com>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.digium.com/pipermail/asterisk-code-review/attachments/20181016/763b59a2/attachment-0001.html>
More information about the asterisk-code-review
mailing list