<p>George Joseph <strong>merged</strong> this change.</p><p><a href="https://gerrit.asterisk.org/10348">View Change</a></p><div style="white-space:pre-wrap">Approvals:
Richard Mudgett: Looks good to me, but someone else must approve
George Joseph: Looks good to me, approved; Approved for Submit
</div><pre style="font-family: monospace,monospace; white-space: pre-wrap;">astobj2: Record lock usage to refs log when DEBUG_THREADS is enabled.<br><br>When DEBUG_THREADS is enabled we can know if the astobj2 mutex / rwlock<br>was ever used, so it can be recorded in the REF_DEBUG destructor entry.<br><br>Create contrib/scripts/reflocks.py to process locking used by<br>allocator. This can be used to identify places where<br>AO2_ALLOC_OPT_LOCK_NOLOCK should be used to reduce memory usage.<br><br>Change-Id: I2e3cd23336a97df2692b545f548fd79b14b53bf4<br>---<br>M contrib/scripts/refcounter.py<br>A contrib/scripts/reflocks.py<br>M main/astobj2.c<br>3 files changed, 157 insertions(+), 2 deletions(-)<br><br></pre><pre style="font-family: monospace,monospace; white-space: pre-wrap;"><span>diff --git a/contrib/scripts/refcounter.py b/contrib/scripts/refcounter.py</span><br><span>index de3cda0..36fb341 100755</span><br><span>--- a/contrib/scripts/refcounter.py</span><br><span>+++ b/contrib/scripts/refcounter.py</span><br><span>@@ -108,6 +108,10 @@</span><br><span> else:</span><br><span> current_objects[obj]['curcount'] += int(parsed_line['delta'])</span><br><span> </span><br><span style="color: hsl(120, 100%, 40%);">+ if 'destructor' in parsed_line['state']:</span><br><span style="color: hsl(120, 100%, 40%);">+ # refcounter.py doesn't care about lock-state.</span><br><span style="color: hsl(120, 100%, 40%);">+ parsed_line['state'] = '**destructor**'</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span> current_objects[obj]['log'].append(</span><br><span> "[%s] %s:%s %s: %s %s - [%s]" % (</span><br><span> parsed_line['thread_id'],</span><br><span>diff --git a/contrib/scripts/reflocks.py b/contrib/scripts/reflocks.py</span><br><span>new file mode 100755</span><br><span>index 0000000..7d8edfc</span><br><span>--- /dev/null</span><br><span>+++ b/contrib/scripts/reflocks.py</span><br><span>@@ -0,0 +1,126 @@</span><br><span style="color: hsl(120, 100%, 40%);">+#!/usr/bin/env python</span><br><span style="color: hsl(120, 100%, 40%);">+"""Process a ref debug log for lock usage</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ This file will process a log file created by Asterisk</span><br><span style="color: hsl(120, 100%, 40%);">+ that was compiled with REF_DEBUG and DEBUG_THREADS.</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ See http://www.asterisk.org for more information about</span><br><span style="color: hsl(120, 100%, 40%);">+ the Asterisk project. Please do not directly contact</span><br><span style="color: hsl(120, 100%, 40%);">+ any of the maintainers of this project for assistance;</span><br><span style="color: hsl(120, 100%, 40%);">+ the project provides a web site, mailing lists and IRC</span><br><span style="color: hsl(120, 100%, 40%);">+ channels for your use.</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ This program is free software, distributed under the terms of</span><br><span style="color: hsl(120, 100%, 40%);">+ the GNU General Public License Version 2. See the LICENSE file</span><br><span style="color: hsl(120, 100%, 40%);">+ at the top of the source tree.</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ Copyright (C) 2018, CFWare, LLC</span><br><span style="color: hsl(120, 100%, 40%);">+ Corey Farrell <git@cfware.com></span><br><span style="color: hsl(120, 100%, 40%);">+"""</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+from __future__ import print_function</span><br><span style="color: hsl(120, 100%, 40%);">+import sys</span><br><span style="color: hsl(120, 100%, 40%);">+import os</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+from optparse import OptionParser</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+def process_file(options):</span><br><span style="color: hsl(120, 100%, 40%);">+ """The routine that kicks off processing a ref file"""</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ object_types = {}</span><br><span style="color: hsl(120, 100%, 40%);">+ objects = {}</span><br><span style="color: hsl(120, 100%, 40%);">+ filename = options.filepath</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ with open(filename, 'r') as ref_file:</span><br><span style="color: hsl(120, 100%, 40%);">+ for line in ref_file:</span><br><span style="color: hsl(120, 100%, 40%);">+ if 'constructor' not in line and 'destructor' not in line:</span><br><span style="color: hsl(120, 100%, 40%);">+ continue</span><br><span style="color: hsl(120, 100%, 40%);">+ # The line format is:</span><br><span style="color: hsl(120, 100%, 40%);">+ # addr,delta,thread_id,file,line,function,state,tag</span><br><span style="color: hsl(120, 100%, 40%);">+ # Only addr, file, line, function, state are used by reflocks.py</span><br><span style="color: hsl(120, 100%, 40%);">+ tokens = line.strip().split(',', 7)</span><br><span style="color: hsl(120, 100%, 40%);">+ addr = tokens[0]</span><br><span style="color: hsl(120, 100%, 40%);">+ state = tokens[6]</span><br><span style="color: hsl(120, 100%, 40%);">+ if 'constructor' in state:</span><br><span style="color: hsl(120, 100%, 40%);">+ obj_type = '%s:%s:%s' % (tokens[3], tokens[4], tokens[5])</span><br><span style="color: hsl(120, 100%, 40%);">+ if obj_type not in object_types:</span><br><span style="color: hsl(120, 100%, 40%);">+ object_types[obj_type] = {</span><br><span style="color: hsl(120, 100%, 40%);">+ 'used': 0,</span><br><span style="color: hsl(120, 100%, 40%);">+ 'unused': 0,</span><br><span style="color: hsl(120, 100%, 40%);">+ 'lockobj': 0,</span><br><span style="color: hsl(120, 100%, 40%);">+ 'none': 0</span><br><span style="color: hsl(120, 100%, 40%);">+ }</span><br><span style="color: hsl(120, 100%, 40%);">+ objects[addr] = obj_type</span><br><span style="color: hsl(120, 100%, 40%);">+ elif 'destructor' in state:</span><br><span style="color: hsl(120, 100%, 40%);">+ if addr not in objects:</span><br><span style="color: hsl(120, 100%, 40%);">+ # This error would be reported by refcounter.py.</span><br><span style="color: hsl(120, 100%, 40%);">+ continue</span><br><span style="color: hsl(120, 100%, 40%);">+ obj_type = objects[addr]</span><br><span style="color: hsl(120, 100%, 40%);">+ del objects[addr]</span><br><span style="color: hsl(120, 100%, 40%);">+ if '**lock-state:unused**' in state:</span><br><span style="color: hsl(120, 100%, 40%);">+ object_types[obj_type]['unused'] += 1</span><br><span style="color: hsl(120, 100%, 40%);">+ elif '**lock-state:used**' in state:</span><br><span style="color: hsl(120, 100%, 40%);">+ object_types[obj_type]['used'] += 1</span><br><span style="color: hsl(120, 100%, 40%);">+ elif '**lock-state:lockobj**' in state:</span><br><span style="color: hsl(120, 100%, 40%);">+ object_types[obj_type]['lockobj'] += 1</span><br><span style="color: hsl(120, 100%, 40%);">+ elif '**lock-state:none**' in state:</span><br><span style="color: hsl(120, 100%, 40%);">+ object_types[obj_type]['none'] += 1</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ for (allocator, info) in object_types.items():</span><br><span style="color: hsl(120, 100%, 40%);">+ stats = [];</span><br><span style="color: hsl(120, 100%, 40%);">+ if info['used'] > 0:</span><br><span style="color: hsl(120, 100%, 40%);">+ if not options.used:</span><br><span style="color: hsl(120, 100%, 40%);">+ continue</span><br><span style="color: hsl(120, 100%, 40%);">+ stats.append("%d used" % info['used'])</span><br><span style="color: hsl(120, 100%, 40%);">+ if info['unused'] > 0:</span><br><span style="color: hsl(120, 100%, 40%);">+ stats.append("%d unused" % info['unused'])</span><br><span style="color: hsl(120, 100%, 40%);">+ if info['lockobj'] > 0 and options.lockobj:</span><br><span style="color: hsl(120, 100%, 40%);">+ stats.append("%d lockobj" % info['lockobj'])</span><br><span style="color: hsl(120, 100%, 40%);">+ if info['none'] > 0 and options.none:</span><br><span style="color: hsl(120, 100%, 40%);">+ stats.append("%d none" % info['none'])</span><br><span style="color: hsl(120, 100%, 40%);">+ if len(stats) == 0:</span><br><span style="color: hsl(120, 100%, 40%);">+ continue</span><br><span style="color: hsl(120, 100%, 40%);">+ print("%s: %s" % (allocator, ', '.join(stats)))</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+def main(argv=None):</span><br><span style="color: hsl(120, 100%, 40%);">+ """Main entry point for the script"""</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ ret_code = 0</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if argv is None:</span><br><span style="color: hsl(120, 100%, 40%);">+ argv = sys.argv</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ parser = OptionParser()</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ parser.add_option("-f", "--file", action="store", type="string",</span><br><span style="color: hsl(120, 100%, 40%);">+ dest="filepath", default="/var/log/asterisk/refs",</span><br><span style="color: hsl(120, 100%, 40%);">+ help="The full path to the refs file to process")</span><br><span style="color: hsl(120, 100%, 40%);">+ parser.add_option("-u", "--suppress-used", action="store_false",</span><br><span style="color: hsl(120, 100%, 40%);">+ dest="used", default=True,</span><br><span style="color: hsl(120, 100%, 40%);">+ help="Don't output types that have used locks.")</span><br><span style="color: hsl(120, 100%, 40%);">+ parser.add_option("-n", "--show-none", action="store_true",</span><br><span style="color: hsl(120, 100%, 40%);">+ dest="none", default=False,</span><br><span style="color: hsl(120, 100%, 40%);">+ help="Show counts of objects with no locking.")</span><br><span style="color: hsl(120, 100%, 40%);">+ parser.add_option("-o", "--show-lockobj", action="store_true",</span><br><span style="color: hsl(120, 100%, 40%);">+ dest="lockobj", default=False,</span><br><span style="color: hsl(120, 100%, 40%);">+ help="Show counts of objects with a lockobj.")</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ (options, args) = parser.parse_args(argv)</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ if not os.path.isfile(options.filepath):</span><br><span style="color: hsl(120, 100%, 40%);">+ print("File not found: %s" % options.filepath, file=sys.stderr)</span><br><span style="color: hsl(120, 100%, 40%);">+ return -1</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ try:</span><br><span style="color: hsl(120, 100%, 40%);">+ process_file(options)</span><br><span style="color: hsl(120, 100%, 40%);">+ except (KeyboardInterrupt, SystemExit, IOError):</span><br><span style="color: hsl(120, 100%, 40%);">+ print("File processing cancelled", file=sys.stderr)</span><br><span style="color: hsl(120, 100%, 40%);">+ return -1</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+ return ret_code</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+</span><br><span style="color: hsl(120, 100%, 40%);">+if __name__ == "__main__":</span><br><span style="color: hsl(120, 100%, 40%);">+ sys.exit(main(sys.argv))</span><br><span>diff --git a/main/astobj2.c b/main/astobj2.c</span><br><span>index 23109a6..d6a8a4e 100644</span><br><span>--- a/main/astobj2.c</span><br><span>+++ b/main/astobj2.c</span><br><span>@@ -473,6 +473,9 @@</span><br><span> int32_t current_value;</span><br><span> int32_t ret;</span><br><span> struct ao2_weakproxy *weakproxy = NULL;</span><br><span style="color: hsl(120, 100%, 40%);">+#ifdef DEBUG_THREADS</span><br><span style="color: hsl(120, 100%, 40%);">+ const char *lock_state;</span><br><span style="color: hsl(120, 100%, 40%);">+#endif</span><br><span> </span><br><span> if (obj == NULL) {</span><br><span> if (ref_log && user_data) {</span><br><span>@@ -592,21 +595,33 @@</span><br><span> switch (obj->priv_data.options & AO2_ALLOC_OPT_LOCK_MASK) {</span><br><span> case AO2_ALLOC_OPT_LOCK_MUTEX:</span><br><span> obj_mutex = INTERNAL_OBJ_MUTEX(user_data);</span><br><span style="color: hsl(120, 100%, 40%);">+#ifdef DEBUG_THREADS</span><br><span style="color: hsl(120, 100%, 40%);">+ lock_state = obj_mutex->mutex.lock.flags.setup ? "used" : "unused";</span><br><span style="color: hsl(120, 100%, 40%);">+#endif</span><br><span> ast_mutex_destroy(&obj_mutex->mutex.lock);</span><br><span> </span><br><span> ast_free(obj_mutex);</span><br><span> break;</span><br><span> case AO2_ALLOC_OPT_LOCK_RWLOCK:</span><br><span> obj_rwlock = INTERNAL_OBJ_RWLOCK(user_data);</span><br><span style="color: hsl(120, 100%, 40%);">+#ifdef DEBUG_THREADS</span><br><span style="color: hsl(120, 100%, 40%);">+ lock_state = obj_rwlock->rwlock.lock.flags.setup ? "used" : "unused";</span><br><span style="color: hsl(120, 100%, 40%);">+#endif</span><br><span> ast_rwlock_destroy(&obj_rwlock->rwlock.lock);</span><br><span> </span><br><span> ast_free(obj_rwlock);</span><br><span> break;</span><br><span> case AO2_ALLOC_OPT_LOCK_NOLOCK:</span><br><span style="color: hsl(120, 100%, 40%);">+#ifdef DEBUG_THREADS</span><br><span style="color: hsl(120, 100%, 40%);">+ lock_state = "none";</span><br><span style="color: hsl(120, 100%, 40%);">+#endif</span><br><span> ast_free(obj);</span><br><span> break;</span><br><span> case AO2_ALLOC_OPT_LOCK_OBJ:</span><br><span> obj_lockobj = INTERNAL_OBJ_LOCKOBJ(user_data);</span><br><span style="color: hsl(120, 100%, 40%);">+#ifdef DEBUG_THREADS</span><br><span style="color: hsl(120, 100%, 40%);">+ lock_state = "lockobj";</span><br><span style="color: hsl(120, 100%, 40%);">+#endif</span><br><span> ao2_t_ref(obj_lockobj->lockobj.lock, -1, "release lockobj");</span><br><span> </span><br><span> ast_free(obj_lockobj);</span><br><span>@@ -614,12 +629,22 @@</span><br><span> default:</span><br><span> ast_log(__LOG_ERROR, file, line, func,</span><br><span> "Invalid lock option on ao2 object %p\n", user_data);</span><br><span style="color: hsl(120, 100%, 40%);">+#ifdef DEBUG_THREADS</span><br><span style="color: hsl(120, 100%, 40%);">+ lock_state = "invalid";</span><br><span style="color: hsl(120, 100%, 40%);">+#endif</span><br><span> break;</span><br><span> }</span><br><span> </span><br><span> if (ref_log && tag) {</span><br><span style="color: hsl(0, 100%, 40%);">- fprintf(ref_log, "%p,%d,%d,%s,%d,%s,**destructor**,%s\n",</span><br><span style="color: hsl(0, 100%, 40%);">- user_data, delta, ast_get_tid(), file, line, func, tag);</span><br><span style="color: hsl(120, 100%, 40%);">+ fprintf(ref_log, "%p,%d,%d,%s,%d,%s,**destructor%s%s**,%s\n",</span><br><span style="color: hsl(120, 100%, 40%);">+ user_data, delta, ast_get_tid(), file, line, func,</span><br><span style="color: hsl(120, 100%, 40%);">+#ifdef DEBUG_THREADS</span><br><span style="color: hsl(120, 100%, 40%);">+ "**lock-state:",</span><br><span style="color: hsl(120, 100%, 40%);">+ lock_state,</span><br><span style="color: hsl(120, 100%, 40%);">+#else</span><br><span style="color: hsl(120, 100%, 40%);">+ "", "",</span><br><span style="color: hsl(120, 100%, 40%);">+#endif</span><br><span style="color: hsl(120, 100%, 40%);">+ tag);</span><br><span> fflush(ref_log);</span><br><span> }</span><br><span> </span><br><span></span><br></pre><p>To view, visit <a href="https://gerrit.asterisk.org/10348">change 10348</a>. To unsubscribe, or for help writing mail filters, visit <a href="https://gerrit.asterisk.org/settings">settings</a>.</p><div itemscope itemtype="http://schema.org/EmailMessage"><div itemscope itemprop="action" itemtype="http://schema.org/ViewAction"><link itemprop="url" href="https://gerrit.asterisk.org/10348"/><meta itemprop="name" content="View Change"/></div></div>
<div style="display:none"> Gerrit-Project: asterisk </div>
<div style="display:none"> Gerrit-Branch: 16 </div>
<div style="display:none"> Gerrit-MessageType: merged </div>
<div style="display:none"> Gerrit-Change-Id: I2e3cd23336a97df2692b545f548fd79b14b53bf4 </div>
<div style="display:none"> Gerrit-Change-Number: 10348 </div>
<div style="display:none"> Gerrit-PatchSet: 1 </div>
<div style="display:none"> Gerrit-Owner: Corey Farrell <git@cfware.com> </div>
<div style="display:none"> Gerrit-Reviewer: George Joseph <gjoseph@digium.com> </div>
<div style="display:none"> Gerrit-Reviewer: Jenkins2 (1000185) </div>
<div style="display:none"> Gerrit-Reviewer: Richard Mudgett <rmudgett@digium.com> </div>