[asterisk-commits] mjordan: branch 11 r412115 - in /branches/11: ./ build_tools/ channels/ chann...
SVN commits to the Asterisk project
asterisk-commits at lists.digium.com
Thu Apr 10 21:10:31 CDT 2014
Author: mjordan
Date: Thu Apr 10 21:10:22 2014
New Revision: 412115
URL: http://svnview.digium.com/svn/asterisk?view=rev&rev=412115
Log:
main/astobj2: Make REF_DEBUG a menuselect item; improve REF_DEBUG output
This patch does the following:
(1) It makes REF_DEBUG a meneselect item. Enabling REF_DEBUG now enables
REF_DEBUG globally throughout Asterisk.
(2) The ref debug log file is now created in the AST_LOG_DIR directory.
Every run will now blow away the previous run (as large ref files
sometimes caused issues). We now also no longer open/close the file
on each write, instead relying on fflush to make sure data gets written
to the file (in case the ao2 call being performed is about to cause a
crash)
(3) It goes with a comma delineated format for the ref debug file. This
makes parsing much easier. This also now includes the thread ID of the
thread that caused ref change.
(4) A new python script instead for refcounting has been added in the
contrib/scripts folder.
Review: https://reviewboard.asterisk.org/r/3377/
........
Merged revisions 412114 from http://svn.asterisk.org/svn/asterisk/branches/1.8
Added:
branches/11/contrib/scripts/refcounter.py
- copied unchanged from r412114, branches/1.8/contrib/scripts/refcounter.py
Modified:
branches/11/ (props changed)
branches/11/build_tools/cflags.xml
branches/11/channels/chan_sip.c
branches/11/channels/sip/security_events.c
branches/11/include/asterisk/astobj2.h
branches/11/main/asterisk.c
branches/11/main/astobj2.c
branches/11/main/utils.c
Propchange: branches/11/
------------------------------------------------------------------------------
Binary property 'branch-1.8-merged' - no diff available.
Modified: branches/11/build_tools/cflags.xml
URL: http://svnview.digium.com/svn/asterisk/branches/11/build_tools/cflags.xml?view=diff&rev=412115&r1=412114&r2=412115
==============================================================================
--- branches/11/build_tools/cflags.xml (original)
+++ branches/11/build_tools/cflags.xml Thu Apr 10 21:10:22 2014
@@ -4,6 +4,9 @@
</member>
<member name="DEBUG_THREADS" displayname="Enable Thread Debugging">
<support_level>core</support_level>
+ </member>
+ <member name="REF_DEBUG" displayname="Enable reference count debugging">
+ <support_level>extended</support_level>
</member>
<member name="STATIC_BUILD" displayname="Build static binaries">
<support_level>extended</support_level>
Modified: branches/11/channels/chan_sip.c
URL: http://svnview.digium.com/svn/asterisk/branches/11/channels/chan_sip.c?view=diff&rev=412115&r1=412114&r2=412115
==============================================================================
--- branches/11/channels/chan_sip.c (original)
+++ branches/11/channels/chan_sip.c Thu Apr 10 21:10:22 2014
@@ -219,21 +219,6 @@
#include "asterisk/network.h"
#include "asterisk/paths.h" /* need ast_config_AST_SYSTEM_NAME */
-/*
- Uncomment the define below, if you are having refcount related memory leaks.
- With this uncommented, this module will generate a file, /tmp/refs, which contains
- a history of the ao2_ref() calls. To be useful, all calls to ao2_* functions should
- be modified to ao2_t_* calls, and include a tag describing what is happening with
- enough detail, to make pairing up a reference count increment with its corresponding decrement.
- The refcounter program in utils/ can be invaluable in highlighting objects that are not
- balanced, along with the complete history for that object.
- In normal operation, the macros defined will throw away the tags, so they do not
- affect the speed of the program at all. They can be considered to be documentation.
-
- Note: This must also be enabled in channels/sip/security_events.c
-*/
-/* #define REF_DEBUG 1 */
-
#include "asterisk/lock.h"
#include "asterisk/config.h"
#include "asterisk/module.h"
Modified: branches/11/channels/sip/security_events.c
URL: http://svnview.digium.com/svn/asterisk/branches/11/channels/sip/security_events.c?view=diff&rev=412115&r1=412114&r2=412115
==============================================================================
--- branches/11/channels/sip/security_events.c (original)
+++ branches/11/channels/sip/security_events.c Thu Apr 10 21:10:22 2014
@@ -31,8 +31,6 @@
#include "asterisk.h"
ASTERISK_FILE_VERSION(__FILE__, "$Revision$")
-
-/* #define REF_DEBUG 1 */
#include "include/sip.h"
#include "include/security_events.h"
Modified: branches/11/include/asterisk/astobj2.h
URL: http://svnview.digium.com/svn/asterisk/branches/11/include/asterisk/astobj2.h?view=diff&rev=412115&r1=412114&r2=412115
==============================================================================
--- branches/11/include/asterisk/astobj2.h (original)
+++ branches/11/include/asterisk/astobj2.h Thu Apr 10 21:10:22 2014
@@ -141,11 +141,10 @@
\note DEBUGGING REF COUNTS BIBLE:
An interface to help debug refcounting is provided
in this package. It is dependent on the REF_DEBUG macro being
-defined in a source file, before the #include of astobj2.h,
-and in using variants of the normal ao2_xxx functions
-that are named ao2_t_xxx instead, with an extra argument, a string,
-that will be printed out into /tmp/refs when the refcount for an
-object is changed.
+defined via menuselect and in using variants of the normal ao2_xxxx
+function that are named ao2_t_xxxx instead, with an extra argument,
+a string that will be printed out into the refs log file when the
+refcount for an object is changed.
these ao2_t_xxx variants are provided:
@@ -164,45 +163,56 @@
enough of an explanation, that you can pair operations that increment the
ref count, with operations that are meant to decrement the refcount.
-Each of these calls will generate at least one line of output in /tmp/refs.
-These lines look like this:
+Each of these calls will generate at least one line of output in in the refs
+log files. These lines look like this:
...
-0x8756f00 =1 chan_sip.c:22240:load_module (allocate users)
-0x86e3408 =1 chan_sip.c:22241:load_module (allocate peers)
-0x86dd380 =1 chan_sip.c:22242:load_module (allocate peers_by_ip)
-0x822d020 =1 chan_sip.c:22243:load_module (allocate dialogs)
-0x8930fd8 =1 chan_sip.c:20025:build_peer (allocate a peer struct)
-0x8930fd8 +1 chan_sip.c:21467:reload_config (link peer into peer table) [@1]
-0x8930fd8 -1 chan_sip.c:2370:unref_peer (unref_peer: from reload_config) [@2]
-0x89318b0 =1 chan_sip.c:20025:build_peer (allocate a peer struct)
-0x89318b0 +1 chan_sip.c:21467:reload_config (link peer into peer table) [@1]
-0x89318b0 -1 chan_sip.c:2370:unref_peer (unref_peer: from reload_config) [@2]
-0x8930218 =1 chan_sip.c:20025:build_peer (allocate a peer struct)
-0x8930218 +1 chan_sip.c:21539:reload_config (link peer into peers table) [@1]
-0x868c040 -1 chan_sip.c:2424:dialog_unlink_all (unset the relatedpeer->call field in tandem with relatedpeer field itself) [@2]
-0x868c040 -1 chan_sip.c:2443:dialog_unlink_all (Let's unbump the count in the unlink so the poor pvt can disappear if it is time) [@1]
-0x868c040 **call destructor** chan_sip.c:2443:dialog_unlink_all (Let's unbump the count in the unlink so the poor pvt can disappear if it is time)
-0x8cc07e8 -1 chan_sip.c:2370:unref_peer (unsetting a dialog relatedpeer field in sip_destroy) [@3]
-0x8cc07e8 +1 chan_sip.c:3876:find_peer (ao2_find in peers table) [@2]
-0x8cc07e8 -1 chan_sip.c:2370:unref_peer (unref_peer, from sip_devicestate, release ref from find_peer) [@3]
+0x8756f00,+1,1234,chan_sip.c,22240,load_module,**constructor**,allocate users
+0x86e3408,+1,1234,chan_sip.c,22241,load_module,**constructor**,allocate peers
+0x86dd380,+1,1234,chan_sip.c,22242,load_module,**constructor**,allocate peers_by_ip
+0x822d020,+1,1234,chan_sip.c,22243,load_module,**constructor**,allocate dialogs
+0x8930fd8,+1,1234,chan_sip.c,20025,build_peer,**constructor**,allocate a peer struct
+0x8930fd8,+1,1234,chan_sip.c,21467,reload_config,1,link peer into peer table
+0x8930fd8,-1,1234,chan_sip.c,2370,unref_peer,2,unref_peer: from reload_config
+0x89318b0,1,5678,chan_sip.c,20025,build_peer,**constructor**,allocate a peer struct
+0x89318b0,+1,5678,chan_sip.c,21467,reload_config,1,link peer into peer table
+0x89318b0,-1,1234,chan_sip.c,2370,unref_peer,2,unref_peer: from reload_config
+0x8930218,+1,1234,chan_sip.c,20025,build_peer,**constructor**,allocate a peer struct
+0x8930218,+1,1234,chan_sip.c,21539,reload_config,1,link peer into peers table
+0x868c040,-1,1234,chan_sip.c,2424,dialog_unlink_all,2,unset the relatedpeer->call field in tandem with relatedpeer field itself
+0x868c040,-1,1234,chan_sip.c,2443,dialog_unlink_all,1,Let's unbump the count in the unlink so the poor pvt can disappear if it is time
+0x868c040,-1,1234,chan_sip.c,2443,dialog_unlink_all,**destructor**,Let's unbump the count in the unlink so the poor pvt can disappear if it is time
+0x8cc07e8,-1,1234,chan_sip.c,2370,unref_peer,3,unsetting a dialog relatedpeer field in sip_destroy
+0x8cc07e8,+1,1234,chan_sip.c,3876,find_peer,2,ao2_find in peers table
+0x8cc07e8,-1,1234,chan_sip.c,2370,unref_peer,3,unref_peer, from sip_devicestate, release ref from find_peer
...
-The first column is the object address.
-The second column reflects how the operation affected the ref count
- for that object. Creation sets the ref count to 1 (=1).
- increment or decrement and amount are specified (-1/+1).
-The remainder of the line specifies where in the file the call was made,
- and the function name, and the tag supplied in the function call.
-
-The **call destructor** is specified when the destroy routine is
-run for an object. It does not affect the ref count, but is important
-in debugging, because it is possible to have the astobj2 system run it
-multiple times on the same object, commonly fatal to asterisk.
+This uses a comma delineated format. The columns in the format are as
+follows:
+- The first column is the object address.
+- The second column reflects how the operation affected the ref count
+ for that object. A change in the ref count is reflected either as
+ an increment (+) or decrement (-), as well as the amount it changed
+ by.
+- The third column is the ID of the thread that modified the reference
+ count.
+- The fourth column is the source file that the change in reference was
+ issued from.
+- The fifth column is the line number of the source file that the ref
+ change was issued from.
+- The sixth column is the name of the function that the ref change was
+ issued from.
+- The seventh column indicates either (a) construction of the object via
+ the special tag **constructor**; (b) destruction of the object via
+ the special tag **destructor**; (c) the previous reference count
+ prior to this reference change.
+- The eighth column is a special tag added by the developer to provide
+ context for the ref change. Note that any subsequent columns are
+ considered to be part of this tag.
Sometimes you have some helper functions to do object ref/unref
operations. Using these normally hides the place where these
functions were called. To get the location where these functions
-were called to appear in /tmp/refs, you can do this sort of thing:
+were called to appear in /refs, you can do this sort of thing:
#ifdef REF_DEBUG
#define dialog_ref(arg1,arg2) dialog_ref_debug((arg1),(arg2), __FILE__, __LINE__, __PRETTY_FUNCTION__)
@@ -250,13 +260,14 @@
well worth the effort to help track these function calls in the code.
To find out why objects are not destroyed (a common bug), you can
-edit the source file to use the ao2_t_* variants, add the #define REF_DEBUG 1
-before the #include "asterisk/astobj2.h" line, and add a descriptive
-tag to each call. Recompile, and run Asterisk, exit asterisk with
-"stop gracefully", which should result in every object being destroyed.
-Then, you can "sort -k 1 /tmp/refs > x1" to get a sorted list of
-all the objects, or you can use "util/refcounter" to scan the file
-for you and output any problems it finds.
+edit the source file to use the ao2_t_* variants, enable REF_DEBUG
+in menuselect, and add a descriptive tag to each call. Recompile,
+and run Asterisk, exit asterisk with "core stop gracefully", which should
+result in every object being destroyed.
+
+Then, you can "sort -k 1 {AST_LOG_DIR}/refs > x1" to get a sorted list of
+all the objects, or you can use "contrib/script/refcounter.py" to scan
+the file for you and output any problems it finds.
The above may seem astronomically more work than it is worth to debug
reference counts, which may be true in "simple" situations, but for
@@ -272,29 +283,29 @@
chan_sip, that was not getting destroyed, after I moved the lines around
to pair operations:
- 0x83787a0 =1 chan_sip.c:5733:sip_alloc (allocate a dialog(pvt) struct)
- 0x83787a0 -1 chan_sip.c:19173:sip_poke_peer (unref dialog at end of sip_poke_peer, obtained from sip_alloc, just before it goes out of scope) [@4]
-
- 0x83787a0 +1 chan_sip.c:5854:sip_alloc (link pvt into dialogs table) [@1]
- 0x83787a0 -1 chan_sip.c:19150:sip_poke_peer (About to change the callid -- remove the old name) [@3]
- 0x83787a0 +1 chan_sip.c:19152:sip_poke_peer (Linking in under new name) [@2]
- 0x83787a0 -1 chan_sip.c:2399:dialog_unlink_all (unlinking dialog via ao2_unlink) [@5]
-
- 0x83787a0 +1 chan_sip.c:19130:sip_poke_peer (copy sip alloc from p to peer->call) [@2]
-
-
- 0x83787a0 +1 chan_sip.c:2996:__sip_reliable_xmit (__sip_reliable_xmit: setting pkt->owner) [@3]
- 0x83787a0 -1 chan_sip.c:2425:dialog_unlink_all (remove all current packets in this dialog, and the pointer to the dialog too as part of __sip_destroy) [@4]
-
- 0x83787a0 +1 chan_sip.c:22356:unload_module (iterate thru dialogs) [@4]
- 0x83787a0 -1 chan_sip.c:22359:unload_module (toss dialog ptr from iterator_next) [@5]
-
-
- 0x83787a0 +1 chan_sip.c:22373:unload_module (iterate thru dialogs) [@3]
- 0x83787a0 -1 chan_sip.c:22375:unload_module (throw away iterator result) [@2]
-
- 0x83787a0 +1 chan_sip.c:2397:dialog_unlink_all (Let's bump the count in the unlink so it doesn't accidentally become dead before we are done) [@4]
- 0x83787a0 -1 chan_sip.c:2436:dialog_unlink_all (Let's unbump the count in the unlink so the poor pvt can disappear if it is time) [@3]
+ 0x83787a0,+1,1234,chan_sip.c,5733,sip_alloc,**constructor**,(allocate a dialog(pvt) struct)
+ 0x83787a0,-1,1234,chan_sip.c,19173,sip_poke_peer,4,(unref dialog at end of sip_poke_peer, obtained from sip_alloc, just before it goes out of scope)
+
+ 0x83787a0,+1,1234,chan_sip.c,5854,sip_alloc,1,(link pvt into dialogs table)
+ 0x83787a0,-1,1234,chan_sip.c,19150,sip_poke_peer,3,(About to change the callid -- remove the old name)
+ 0x83787a0,+1,1234,chan_sip.c,19152,sip_poke_peer,2,(Linking in under new name)
+ 0x83787a0,-1,1234,chan_sip.c,2399,dialog_unlink_all,5,(unlinking dialog via ao2_unlink)
+
+ 0x83787a0,+1,1234,chan_sip.c,19130,sip_poke_peer,2,(copy sip alloc from p to peer->call)
+
+
+ 0x83787a0,+1,1234,chan_sip.c,2996,__sip_reliable_xmit,3,(__sip_reliable_xmit: setting pkt->owner)
+ 0x83787a0,-1,1234,chan_sip.c,2425,dialog_unlink_all,4,(remove all current packets in this dialog, and the pointer to the dialog too as part of __sip_destroy)
+
+ 0x83787a0,+1,1234,chan_sip.c,22356,unload_module,4,(iterate thru dialogs)
+ 0x83787a0,-1,1234,chan_sip.c,22359,unload_module,5,(toss dialog ptr from iterator_next)
+
+
+ 0x83787a0,+1,1234,chan_sip.c,22373,unload_module,3,(iterate thru dialogs)
+ 0x83787a0,-1,1234,chan_sip.c,22375,unload_module,2,(throw away iterator result)
+
+ 0x83787a0,+1,1234,chan_sip.c,2397,dialog_unlink_all,4,(Let's bump the count in the unlink so it doesn't accidentally become dead before we are done)
+ 0x83787a0,-1,1234,chan_sip.c,2436,dialog_unlink_all,3,(Let's unbump the count in the unlink so the poor pvt can disappear if it is time)
As you can see, only one unbalanced operation is in the list, a ref count increment when
the peer->call was set, but no corresponding decrement was made...
Modified: branches/11/main/asterisk.c
URL: http://svnview.digium.com/svn/asterisk/branches/11/main/asterisk.c?view=diff&rev=412115&r1=412114&r2=412115
==============================================================================
--- branches/11/main/asterisk.c (original)
+++ branches/11/main/asterisk.c Thu Apr 10 21:10:22 2014
@@ -4128,6 +4128,8 @@
register_config_cli();
read_config_maps();
+ astobj2_init();
+
if (ast_opt_console) {
if (el_hist == NULL || el == NULL)
ast_el_initialize();
@@ -4208,8 +4210,6 @@
threadstorage_init();
- astobj2_init();
-
ast_format_attr_init();
ast_format_list_init();
ast_rtp_engine_init();
Modified: branches/11/main/astobj2.c
URL: http://svnview.digium.com/svn/asterisk/branches/11/main/astobj2.c?view=diff&rev=412115&r1=412114&r2=412115
==============================================================================
--- branches/11/main/astobj2.c (original)
+++ branches/11/main/astobj2.c Thu Apr 10 21:10:22 2014
@@ -31,12 +31,14 @@
#include "asterisk/linkedlists.h"
#include "asterisk/utils.h"
#include "asterisk/cli.h"
-#define REF_FILE "/tmp/refs"
+#include "asterisk/paths.h"
#if defined(TEST_FRAMEWORK)
/* We are building with the test framework enabled so enable AO2 debug tests as well. */
#define AO2_DEBUG 1
#endif /* defined(TEST_FRAMEWORK) */
+
+static FILE *ref_log;
/*!
* astobj2 objects are always preceded by this data structure,
@@ -516,22 +518,18 @@
{
struct astobj2 *obj = INTERNAL_OBJ(user_data);
- if (obj == NULL)
+ if (obj == NULL) {
return -1;
-
- if (delta != 0) {
- FILE *refo = fopen(REF_FILE, "a");
- if (refo) {
- fprintf(refo, "%p %s%d %s:%d:%s (%s) [@%d]\n", user_data, (delta < 0 ? "" : "+"),
- delta, file, line, func, tag, obj->priv_data.ref_counter);
- fclose(refo);
- }
- }
- if (obj->priv_data.ref_counter + delta == 0 && obj->priv_data.destructor_fn != NULL) { /* this isn't protected with lock; just for o/p */
- FILE *refo = fopen(REF_FILE, "a");
- if (refo) {
- fprintf(refo, "%p **call destructor** %s:%d:%s (%s)\n", user_data, file, line, func, tag);
- fclose(refo);
+ }
+
+ if (ref_log) {
+ if (obj->priv_data.ref_counter + 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);
+ fflush(ref_log);
}
}
return internal_ao2_ref(user_data, delta, file, line, func);
@@ -622,15 +620,14 @@
{
/* allocation */
void *obj;
- FILE *refo;
if ((obj = internal_ao2_alloc(data_size, destructor_fn, options, file, line, func)) == NULL) {
return NULL;
}
- if (ref_debug && (refo = fopen(REF_FILE, "a"))) {
- fprintf(refo, "%p =1 %s:%d:%s (%s)\n", obj, file, line, func, tag);
- fclose(refo);
+ if (ref_log) {
+ fprintf(ref_log, "%p,+1,%d,%s,%d,%s,**constructor**,%s\n", obj, ast_get_tid(), file, line, func, tag);
+ fflush(ref_log);
}
/* return a pointer to the user data */
@@ -1711,19 +1708,39 @@
AST_CLI_DEFINE(handle_astobj2_stats, "Print astobj2 statistics"),
AST_CLI_DEFINE(handle_astobj2_test, "Test astobj2"),
};
+#endif /* AO2_DEBUG */
static void astobj2_cleanup(void)
{
+#ifdef AO2_DEBUG
ast_cli_unregister_multiple(cli_astobj2, ARRAY_LEN(cli_astobj2));
-}
-#endif /* AO2_DEBUG */
+#endif
+
+#ifdef REF_DEBUG
+ fclose(ref_log);
+ ref_log = NULL;
+#endif
+}
int astobj2_init(void)
{
+#ifdef REF_DEBUG
+ char ref_filename[1024];
+#endif
+
+#ifdef REF_DEBUG
+ snprintf(ref_filename, sizeof(ref_filename), "%s/refs", ast_config_AST_LOG_DIR);
+ ref_log = fopen(ref_filename, "w");
+ if (!ref_log) {
+ ast_log(LOG_ERROR, "Could not open ref debug log file: %s\n", ref_filename);
+ }
+#endif
+
#ifdef AO2_DEBUG
ast_cli_register_multiple(cli_astobj2, ARRAY_LEN(cli_astobj2));
+#endif
+
ast_register_atexit(astobj2_cleanup);
-#endif
return 0;
}
Modified: branches/11/main/utils.c
URL: http://svnview.digium.com/svn/asterisk/branches/11/main/utils.c?view=diff&rev=412115&r1=412114&r2=412115
==============================================================================
--- branches/11/main/utils.c (original)
+++ branches/11/main/utils.c Thu Apr 10 21:10:22 2014
@@ -33,7 +33,14 @@
#include <ctype.h>
#include <sys/stat.h>
-#include <sys/stat.h>
+
+#include <sys/syscall.h>
+#include <unistd.h>
+#if defined(__APPLE__)
+#include <mach/mach.h>
+#elif defined(HAVE_SYS_THR_H)
+#include <sys/thr.h>
+#endif
#ifdef HAVE_DEV_URANDOM
#include <fcntl.h>
More information about the asterisk-commits
mailing list