astobj2: work around REF_DEBUG race which causes out of order log entries

* Update refcounter.py to use delta's to track the current reference count.
* Use result from internal_ao2_ref to write old_refcount to refs_log.

Review: https://reviewboard.asterisk.org/r/3756/
........

Merged revisions 418504 from http://svn.asterisk.org/svn/asterisk/branches/1.8
........

Merged revisions 418505 from http://svn.asterisk.org/svn/asterisk/branches/11
........

Merged revisions 418506 from http://svn.asterisk.org/svn/asterisk/branches/12


git-svn-id: https://origsvn.digium.com/svn/asterisk/trunk@418507 65c4cc65-6c06-0410-ace0-fbb531ad65f3

contrib/scripts/refcounter.py

@@ -79,10 +79,15 @@ def process_file(options):
             obj = parsed_line['addr']
 
             if obj not in current_objects:
-                current_objects[obj] = []
-                if options.skewed and 'constructor' not in parsed_line['state']:
-                    skewed_objects.append((obj, current_objects[obj]))
-            current_objects[obj].append("[%s] %s:%s %s: %s %s - [%s]" % (
+                current_objects[obj] = {'log': [], 'curcount': 1,}
+                if 'constructor' not in parsed_line['state']:
+                    current_objects[obj]['curcount'] = parsed_line['state']
+                    if options.skewed:
+                        skewed_objects.append((obj, current_objects[obj]))
+            else:
+                current_objects[obj]['curcount'] += int(parsed_line['delta'])
+
+            current_objects[obj]['log'].append("[%s] %s:%s %s: %s %s - [%s]" % (
                 parsed_line['thread_id'],
                 parsed_line['file'],
                 parsed_line['line'],
@@ -91,7 +96,7 @@ def process_file(options):
                 parsed_line['tag'],
                 parsed_line['state']))
 
-            if 'destructor' in parsed_line['state']:
+            if current_objects[obj]['curcount'] == 0:
                 if options.normal:
                     finished_objects.append((obj, current_objects[obj]))
                 del current_objects[obj]
@@ -115,7 +120,7 @@ def print_objects(objects, prefix=""):
     print "\n"
     for obj in objects:
         print "==== %s Object %s history ====" % (prefix, obj[0])
-        for line in obj[1]:
+        for line in obj[1]['log']:
             print line
         print "\n"
 

main/astobj2.c

@@ -498,14 +498,19 @@ static int internal_ao2_ref(void *user_data, int delta, const char *file, int li
 int __ao2_ref_debug(void *user_data, int delta, const char *tag, const char *file, int line, const char *func)
 {
 	struct astobj2 *obj = INTERNAL_OBJ(user_data);
+	int old_refcount = -1;
+
+	if (obj) {
+		old_refcount = internal_ao2_ref(user_data, delta, file, line, func);
+	}
 
 	if (ref_log && user_data) {
-		if (obj && obj->priv_data.ref_counter + delta == 0) {
+		if (obj && old_refcount + delta == 0) {
 			fprintf(ref_log, "%p,%d,%d,%s,%d,%s,**destructor**,%s\n", user_data, delta, ast_get_tid(), file, line, func, tag);
 			fflush(ref_log);
 		} else if (delta != 0) {
 			fprintf(ref_log, "%p,%s%d,%d,%s,%d,%s,%d,%s\n", user_data, (delta < 0 ? "" : "+"),
-				delta, ast_get_tid(), file, line, func, obj ? obj->priv_data.ref_counter : -1, tag);
+				delta, ast_get_tid(), file, line, func, old_refcount, tag);
 			fflush(ref_log);
 		}
 	}
@@ -513,10 +518,9 @@ int __ao2_ref_debug(void *user_data, int delta, const char *tag, const char *fil
 	if (obj == NULL) {
 		ast_log_backtrace();
 		ast_assert(0);
-		return -1;
 	}
 
-	return internal_ao2_ref(user_data, delta, file, line, func);
+	return old_refcount;
 }
 
 int __ao2_ref(void *user_data, int delta)