log: Add a new debug level (4) for verbose I/O debug

Change ftdi SWD driver and CMSIS-DAP to use it instead of LOG_DEBUG().

Change-Id: I17ba3de2086c7159209db61fba3faf067dfc5023
Signed-off-by: Andreas Fritiofson <andreas.fritiofson@gmail.com>
Reviewed-on: http://openocd.zylin.com/3805
Tested-by: jenkins
Reviewed-by: Tomas Vanek <vanekt@fbl.cz>

5 files changed, 29 insertions, 15 deletions

diff --git a/doc/openocd.texi b/doc/openocd.texi
index 30d8aaeb..959f7189 100644
--- a/doc/openocd.texi
+++ b/doc/openocd.texi
@@ -682,7 +682,8 @@ bash$ openocd --help
 --version    | -v       display OpenOCD version
 --file       | -f       use configuration file <name>
 --search     | -s       dir to search for config files and scripts
---debug      | -d       set debug level <0-3>
+--debug      | -d       set debug level to 3
+             | -d<n>    set debug level to <level>
 --log_output | -l       redirect log output to file <name>
 --command    | -c       run <command>
 @end verbatim
@@ -6849,12 +6850,13 @@ non-zero exit code to the parent process.
 @deffn Command debug_level [n]
 @cindex message level
 Display debug level.
-If @var{n} (from 0..3) is provided, then set it to that level.
+If @var{n} (from 0..4) is provided, then set it to that level.
 This affects the kind of messages sent to the server log.
 Level 0 is error messages only;
 level 1 adds warnings;
 level 2 adds informational messages;
-and level 3 adds debugging messages.
+level 3 adds debugging messages;
+and level 4 adds verbose low-level debug messages.
 The default is level 2, but that can be overridden on
 the command line along with the location of that log
 file (which is normally the server's standard output).
diff --git a/src/helper/log.c b/src/helper/log.c
index 891613d3..49b9bd98 100644
--- a/src/helper/log.c
+++ b/src/helper/log.c
@@ -50,11 +50,12 @@ static int64_t current_time;
 
 static int64_t start;
 
-static const char * const log_strings[5] = {
+static const char * const log_strings[6] = {
 	"User : ",
 	"Error: ",
 	"Warn : ",	/* want a space after each colon, all same width, colons aligned */
 	"Info : ",
+	"Debug: ",
 	"Debug: "
 };
 
@@ -234,8 +235,8 @@ COMMAND_HANDLER(handle_debug_level_command)
 	if (CMD_ARGC == 1) {
 		int new_level;
 		COMMAND_PARSE_NUMBER(int, CMD_ARGV[0], new_level);
-		if ((new_level > LOG_LVL_DEBUG) || (new_level < LOG_LVL_SILENT)) {
-			LOG_ERROR("level must be between %d and %d", LOG_LVL_SILENT, LOG_LVL_DEBUG);
+		if ((new_level > LOG_LVL_DEBUG_IO) || (new_level < LOG_LVL_SILENT)) {
+			LOG_ERROR("level must be between %d and %d", LOG_LVL_SILENT, LOG_LVL_DEBUG_IO);
 			return ERROR_COMMAND_SYNTAX_ERROR;
 		}
 		debug_level = new_level;
@@ -279,7 +280,8 @@ static struct command_registration log_command_handlers[] = {
 		.mode = COMMAND_ANY,
 		.help = "Sets the verbosity level of debugging output. "
 			"0 shows errors only; 1 adds warnings; "
-			"2 (default) adds other info; 3 adds debugging.",
+			"2 (default) adds other info; 3 adds debugging; "
+			"4 adds extra verbose debugging.",
 		.usage = "number",
 	},
 	COMMAND_REGISTRATION_DONE
@@ -303,7 +305,7 @@ void log_init(void)
 		int retval = parse_int(debug_env, &value);
 		if (ERROR_OK == retval &&
 				debug_level >= LOG_LVL_SILENT &&
-				debug_level <= LOG_LVL_DEBUG)
+				debug_level <= LOG_LVL_DEBUG_IO)
 				debug_level = value;
 	}
 
diff --git a/src/helper/log.h b/src/helper/log.h
index 6b938165..512bcc51 100644
--- a/src/helper/log.h
+++ b/src/helper/log.h
@@ -46,6 +46,7 @@
  * LOG_LVL_WARNING - non-fatal errors, that may be resolved later
  * LOG_LVL_INFO - state information, etc.
  * LOG_LVL_DEBUG - debug statements, execution trace
+ * LOG_LVL_DEBUG_IO - verbose debug, low-level I/O trace
  */
 enum log_levels {
 	LOG_LVL_SILENT = -3,
@@ -54,7 +55,8 @@ enum log_levels {
 	LOG_LVL_ERROR = 0,
 	LOG_LVL_WARNING = 1,
 	LOG_LVL_INFO = 2,
-	LOG_LVL_DEBUG = 3
+	LOG_LVL_DEBUG = 3,
+	LOG_LVL_DEBUG_IO = 4,
 };
 
 void log_printf(enum log_levels level, const char *file, unsigned line,
@@ -102,6 +104,14 @@ extern int debug_level;
 
 #define LOG_LEVEL_IS(FOO)  ((debug_level) >= (FOO))
 
+#define LOG_DEBUG_IO(expr ...) \
+	do { \
+		if (debug_level >= LOG_LVL_DEBUG_IO) \
+			log_printf_lf(LOG_LVL_DEBUG, \
+				__FILE__, __LINE__, __func__, \
+				expr); \
+	} while (0)
+
 #define LOG_DEBUG(expr ...) \
 	do { \
 		if (debug_level >= LOG_LVL_DEBUG) \
diff --git a/src/jtag/drivers/cmsis_dap_usb.c b/src/jtag/drivers/cmsis_dap_usb.c
index 86f79687..19c3b19c 100644
--- a/src/jtag/drivers/cmsis_dap_usb.c
+++ b/src/jtag/drivers/cmsis_dap_usb.c
@@ -596,7 +596,7 @@ static int cmsis_dap_swd_run_queue(void)
 {
 	uint8_t *buffer = cmsis_dap_handle->packet_buffer;
 
-	LOG_DEBUG("Executing %d queued transactions", pending_transfer_count);
+	LOG_DEBUG_IO("Executing %d queued transactions", pending_transfer_count);
 
 	if (queued_retval != ERROR_OK) {
 		LOG_DEBUG("Skipping due to previous errors: %d", queued_retval);
@@ -616,7 +616,7 @@ static int cmsis_dap_swd_run_queue(void)
 		uint8_t cmd = pending_transfers[i].cmd;
 		uint32_t data = pending_transfers[i].data;
 
-		LOG_DEBUG("%s %s reg %x %"PRIx32,
+		LOG_DEBUG_IO("%s %s reg %x %"PRIx32,
 				cmd & SWD_CMD_APnDP ? "AP" : "DP",
 				cmd & SWD_CMD_RnW ? "read" : "write",
 			  (cmd & SWD_CMD_A32) >> 1, data);
@@ -674,7 +674,7 @@ static int cmsis_dap_swd_run_queue(void)
 			uint32_t tmp = data;
 			idx += 4;
 
-			LOG_DEBUG("Read result: %"PRIx32, data);
+			LOG_DEBUG_IO("Read result: %"PRIx32, data);
 
 			/* Imitate posted AP reads */
 			if ((pending_transfers[i].cmd & SWD_CMD_APnDP) ||
diff --git a/src/jtag/drivers/ftdi.c b/src/jtag/drivers/ftdi.c
index 00fe37fa..342e3210 100644
--- a/src/jtag/drivers/ftdi.c
+++ b/src/jtag/drivers/ftdi.c
@@ -1074,12 +1074,12 @@ static void ftdi_swd_swdio_en(bool enable)
  */
 static int ftdi_swd_run_queue(void)
 {
-	LOG_DEBUG("Executing %zu queued transactions", swd_cmd_queue_length);
+	LOG_DEBUG_IO("Executing %zu queued transactions", swd_cmd_queue_length);
 	int retval;
 	struct signal *led = find_signal_by_name("LED");
 
 	if (queued_retval != ERROR_OK) {
-		LOG_DEBUG("Skipping due to previous errors: %d", queued_retval);
+		LOG_DEBUG_IO("Skipping due to previous errors: %d", queued_retval);
 		goto skip;
 	}
 
@@ -1100,7 +1100,7 @@ static int ftdi_swd_run_queue(void)
 	for (size_t i = 0; i < swd_cmd_queue_length; i++) {
 		int ack = buf_get_u32(swd_cmd_queue[i].trn_ack_data_parity_trn, 1, 3);
 
-		LOG_DEBUG("%s %s %s reg %X = %08"PRIx32,
+		LOG_DEBUG_IO("%s %s %s reg %X = %08"PRIx32,
 				ack == SWD_ACK_OK ? "OK" : ack == SWD_ACK_WAIT ? "WAIT" : ack == SWD_ACK_FAULT ? "FAULT" : "JUNK",
 				swd_cmd_queue[i].cmd & SWD_CMD_APnDP ? "AP" : "DP",
 				swd_cmd_queue[i].cmd & SWD_CMD_RnW ? "read" : "write",