diff --git a/contrib/Makefile b/contrib/Makefile index 9512de540cee2ba87ae55b6ee587fe86f26a04fc..074a12b774f953a33315be241105393607a6fd91 100644 --- a/contrib/Makefile +++ b/contrib/Makefile @@ -25,9 +25,13 @@ install: $(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 36fb34126ad74d66e30c41b84290c4c13c6ca033..146a024c90c876184492f2d0fd539f29157a35f0 100755 --- a/contrib/scripts/refcounter.py +++ b/contrib/scripts/refcounter.py @@ -108,8 +108,10 @@ def process_file(options): 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 7d8edfcd054c79d6d6ab893a9f206d8dc75dc1ee..db1985f8a53c9b57d165d094861917e5addf4e17 100755 --- a/contrib/scripts/reflocks.py +++ b/contrib/scripts/reflocks.py @@ -48,7 +48,6 @@ def process_file(options): object_types[obj_type] = { 'used': 0, 'unused': 0, - 'lockobj': 0, 'none': 0 } objects[addr] = obj_type @@ -62,8 +61,6 @@ def process_file(options): 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 @@ def process_file(options): 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 @@ def main(argv=None): 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 0000000000000000000000000000000000000000..93df02f64ac11deab430e4289341cd46a0a696a6 --- /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@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 d6a8a4eb457cd12837e28a5d4f693d8c1daa0345..ebc07200dd4ea8e91094f1b814e68ccccb2a7aad 100644 --- a/main/astobj2.c +++ b/main/astobj2.c @@ -61,15 +61,40 @@ struct __priv_data { #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 @@ int __ao2_lock(void *user_data, enum ao2_lock_req lock_how, const char *file, co 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 @@ int __ao2_trylock(void *user_data, enum ao2_lock_req lock_how, const char *file, 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 @@ int __ao2_trylock(void *user_data, enum ao2_lock_req lock_how, const char *file, return -1; } - return res; } @@ -473,9 +505,7 @@ int __ao2_ref(void *user_data, int delta, 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 @@ int __ao2_ref(void *user_data, int delta, 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 @@ int __ao2_ref(void *user_data, int delta, 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 @@ static void *internal_ao2_alloc(size_t data_size, ao2_destructor_fn destructor_f 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 @@ static void *internal_ao2_alloc(size_t data_size, ao2_destructor_fn destructor_f 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 @@ static void *internal_ao2_alloc(size_t data_size, ao2_destructor_fn destructor_f 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 @@ static void *internal_ao2_alloc(size_t data_size, ao2_destructor_fn destructor_f 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 @@ static void *internal_ao2_alloc(size_t data_size, ao2_destructor_fn destructor_f #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); }