func_frame_trace: Add CLI command to dump frame queue.

This adds a simple CLI command that can be used for
analyzing all frames currently queued to a channel.

A couple log messages are also adjusted to be more
useful in tracing bridging problems.

Resolves: #533

Author: InterLinked1

funcs/func_frame_trace.c

@@ -35,6 +35,7 @@
 #include "asterisk/channel.h"
 #include "asterisk/pbx.h"
 #include "asterisk/framehook.h"
+#include "asterisk/cli.h"
 
 /*** DOCUMENTATION
 	<function name="FRAME_TRACE" language="en_US">
@@ -438,14 +439,64 @@ static struct ast_custom_function frame_trace_function = {
 	.write = frame_trace_helper,
 };
 
+static char *handle_dump_frames(struct ast_cli_entry *e, int cmd, struct ast_cli_args *a)
+{
+	struct ast_channel *chan;
+	struct ast_frame *f;
+	int c = 1;
+
+	switch (cmd) {
+	case CLI_INIT:
+		e->command = "channel dump frames";
+		e->usage =
+			"Usage: channel dump frames <channel>\n"
+			"       List all frames queued to a channel.\n";
+		return NULL;
+	case CLI_GENERATE:
+		return ast_complete_channels(a->line, a->word, a->pos, a->n, 3);
+	}
+
+	if (a->argc != 4) {
+		return CLI_SHOWUSAGE;
+	}
+
+	chan = ast_channel_get_by_name(a->argv[3]);
+	if (!chan) {
+		ast_cli(a->fd, "%s is not a known channel\n", a->argv[3]);
+		return CLI_SUCCESS;
+	}
+
+	ast_channel_lock(chan);
+
+	ast_cli(a->fd, "== Frame list for %s ==\n", ast_channel_name(chan));
+	ast_cli(a->fd, "%5s %6s %6s %-15s (%-20s) - %s\n", "#", "Seqno", "Stream", "Frame Type", "Frame Subclass", "Src");
+	AST_LIST_TRAVERSE(ast_channel_readq(chan), f, frame_list) {
+		char type[64];
+		char subclass[64];
+		ast_frame_type2str(f->frametype, type, sizeof(type));
+		ast_frame_subclass2str(f, subclass, sizeof(subclass), NULL, 0);
+		ast_cli(a->fd, "%5d %6d %6d %-15s (%-20s) - %s\n", c++, f->seqno, f->stream_num, type, subclass, S_OR(f->src, ""));
+	}
+
+	ast_channel_unlock(chan);
+	ast_channel_unref(chan);
+	return CLI_SUCCESS;
+}
+
+static struct ast_cli_entry cli_frames[] = {
+	AST_CLI_DEFINE(handle_dump_frames, "Display frames queued on a specific channel")
+};
+
 static int unload_module(void)
 {
+	ast_cli_unregister_multiple(cli_frames, ARRAY_LEN(cli_frames));
 	return ast_custom_function_unregister(&frame_trace_function);
 }
 
 static int load_module(void)
 {
 	int res = ast_custom_function_register(&frame_trace_function);
+	res |= ast_cli_register_multiple(cli_frames, ARRAY_LEN(cli_frames));
 	return res ? AST_MODULE_LOAD_DECLINE : AST_MODULE_LOAD_SUCCESS;
 }
 

main/channel.c

@@ -1080,8 +1080,11 @@ static int __ast_queue_frame(struct ast_channel *chan, struct ast_frame *fin, in
 	}
 
 	if ((queued_frames + new_frames > 128 || queued_voice_frames + new_voice_frames > 96)) {
+		int total_queued = queued_frames + new_frames;
+		int total_voice = queued_voice_frames + new_voice_frames;
 		int count = 0;
-		ast_log(LOG_WARNING, "Exceptionally long %squeue length queuing to %s\n", queued_frames + new_frames > 128 ? "" : "voice ", ast_channel_name(chan));
+		ast_log(LOG_WARNING, "Exceptionally long %squeue length (%d voice / %d total) queuing to %s\n",
+			queued_frames + new_frames > 128 ? "" : "voice ", total_voice, total_queued, ast_channel_name(chan));
 		AST_LIST_TRAVERSE_SAFE_BEGIN(ast_channel_readq(chan), cur, frame_list) {
 			/* Save the most recent frame */
 			if (!AST_LIST_NEXT(cur, frame_list)) {
@@ -1098,6 +1101,9 @@ static int __ast_queue_frame(struct ast_channel *chan, struct ast_frame *fin, in
 			}
 		}
 		AST_LIST_TRAVERSE_SAFE_END;
+		if (count) {
+			ast_debug(4, "Discarded %d frame%s due to queue overload on %s\n", count, ESS(count), ast_channel_name(chan));
+		}
 	}
 
 	if (after) {