Fix debug prints when loading to flash

While loading to flash with debug level at least 3,
OpenOCD tries to print the whole loaded bitstream.
This will be very-very-slow due to implementation of
conversion from buffer to string.

* fix condition on selected debug level in jtag/core.c
* replace slow buf_to_str function from helper/binarybuffer.c
  with faster but_to_hex_str function

Change-Id: I3dc01d5846941ca80736f2ed12e3a54114d2b6dd
Signed-off-by: Samuel Obuch <sobuch@codasip.com>
Reviewed-on: http://openocd.zylin.com/5800
Tested-by: jenkins
Reviewed-by: Jan Matyas <matyas@codasip.com>
Reviewed-by: Antonio Borneo <borneo.antonio@gmail.com>

7 files changed, 31 insertions, 58 deletions

diff --git a/src/helper/binarybuffer.c b/src/helper/binarybuffer.c
index 76f657f8d..44d139f58 100644
--- a/src/helper/binarybuffer.c
+++ b/src/helper/binarybuffer.c
@@ -199,45 +199,20 @@ static int ceil_f_to_u32(float x)
 	return y;
 }
 
-char *buf_to_str(const void *_buf, unsigned buf_len, unsigned radix)
+char *buf_to_hex_str(const void *_buf, unsigned buf_len)
 {
-	float factor;
-	switch (radix) {
-		case 16:
-			factor = 2.0;	/* log(256) / log(16) = 2.0 */
-			break;
-		case 10:
-			factor = 2.40824;	/* log(256) / log(10) = 2.40824 */
-			break;
-		case 8:
-			factor = 2.66667;	/* log(256) / log(8) = 2.66667 */
-			break;
-		default:
-			return NULL;
-	}
-
-	unsigned str_len = ceil_f_to_u32(DIV_ROUND_UP(buf_len, 8) * factor);
-	char *str = calloc(str_len + 1, 1);
+	unsigned len_bytes = DIV_ROUND_UP(buf_len, 8);
+	char *str = calloc(len_bytes * 2 + 1, 1);
 
 	const uint8_t *buf = _buf;
-	int b256_len = DIV_ROUND_UP(buf_len, 8);
-	for (int i = b256_len - 1; i >= 0; i--) {
-		uint32_t tmp = buf[i];
-		if (((unsigned)i == (buf_len / 8)) && (buf_len % 8))
+	for (unsigned i = 0; i < len_bytes; i++) {
+		uint8_t tmp = buf[len_bytes - i - 1];
+		if ((i == 0) && (buf_len % 8))
 			tmp &= (0xff >> (8 - (buf_len % 8)));
-
-		/* base-256 digits */
-		for (unsigned j = str_len; j > 0; j--) {
-			tmp += (uint32_t)str[j-1] * 256;
-			str[j-1] = (uint8_t)(tmp % radix);
-			tmp /= radix;
-		}
+		str[2 * i] = hex_digits[tmp >> 4];
+		str[2 * i + 1] = hex_digits[tmp & 0xf];
 	}
 
-	const char * const DIGITS = "0123456789ABCDEF";
-	for (unsigned j = 0; j < str_len; j++)
-		str[j] = DIGITS[(int)str[j]];
-
 	return str;
 }
 
diff --git a/src/helper/binarybuffer.h b/src/helper/binarybuffer.h
index 3f2481d9a..36d6adc6f 100644
--- a/src/helper/binarybuffer.h
+++ b/src/helper/binarybuffer.h
@@ -201,7 +201,7 @@ void *buf_set_buf(const void *src, unsigned src_start,
 
 int str_to_buf(const char *str, unsigned len,
 		void *bin_buf, unsigned buf_size, unsigned radix);
-char *buf_to_str(const void *buf, unsigned size, unsigned radix);
+char *buf_to_hex_str(const void *buf, unsigned size);
 
 /* read a uint32_t from a buffer in target memory endianness */
 static inline uint32_t fast_target_buffer_get_u32(const void *p, bool le)
diff --git a/src/jtag/commands.c b/src/jtag/commands.c
index e88a3b74f..cafb05b5b 100644
--- a/src/jtag/commands.c
+++ b/src/jtag/commands.c
@@ -214,10 +214,10 @@ int jtag_build_buffer(const struct scan_command *cmd, uint8_t **buffer)
 	for (i = 0; i < cmd->num_fields; i++) {
 		if (cmd->fields[i].out_value) {
 			if (LOG_LEVEL_IS(LOG_LVL_DEBUG_IO)) {
-				char *char_buf = buf_to_str(cmd->fields[i].out_value,
+				char *char_buf = buf_to_hex_str(cmd->fields[i].out_value,
 						(cmd->fields[i].num_bits > DEBUG_JTAG_IOZ)
 						? DEBUG_JTAG_IOZ
-								: cmd->fields[i].num_bits, 16);
+								: cmd->fields[i].num_bits);
 
 				LOG_DEBUG("fields[%i].out_value[%i]: 0x%s", i,
 						cmd->fields[i].num_bits, char_buf);
@@ -257,10 +257,10 @@ int jtag_read_buffer(uint8_t *buffer, const struct scan_command *cmd)
 					malloc(DIV_ROUND_UP(num_bits, 8)), 0, num_bits);
 
 			if (LOG_LEVEL_IS(LOG_LVL_DEBUG_IO)) {
-				char *char_buf = buf_to_str(captured,
+				char *char_buf = buf_to_hex_str(captured,
 						(num_bits > DEBUG_JTAG_IOZ)
 						? DEBUG_JTAG_IOZ
-								: num_bits, 16);
+								: num_bits);
 
 				LOG_DEBUG("fields[%i].in_value[%i]: 0x%s",
 						i, num_bits, char_buf);
diff --git a/src/jtag/core.c b/src/jtag/core.c
index 1d424b2e4..b8d0b74c0 100644
--- a/src/jtag/core.c
+++ b/src/jtag/core.c
@@ -891,8 +891,8 @@ static int jtag_check_value_inner(uint8_t *captured, uint8_t *in_check_value,
 
 		/* NOTE:  we've lost diagnostic context here -- 'which tap' */
 
-		captured_str = buf_to_str(captured, bits, 16);
-		in_check_value_str = buf_to_str(in_check_value, bits, 16);
+		captured_str = buf_to_hex_str(captured, bits);
+		in_check_value_str = buf_to_hex_str(in_check_value, bits);
 
 		LOG_WARNING("Bad value '%s' captured during DR or IR scan:",
 			captured_str);
@@ -904,7 +904,7 @@ static int jtag_check_value_inner(uint8_t *captured, uint8_t *in_check_value,
 		if (in_check_mask) {
 			char *in_check_mask_str;
 
-			in_check_mask_str = buf_to_str(in_check_mask, bits, 16);
+			in_check_mask_str = buf_to_hex_str(in_check_mask, bits);
 			LOG_WARNING(" check_mask: 0x%s", in_check_mask_str);
 			free(in_check_mask_str);
 		}
@@ -960,7 +960,7 @@ int default_interface_jtag_execute_queue(void)
 	 * jtag/Makefile.am if MINIDRIVER_DUMMY || !MINIDRIVER, but those variables
 	 * aren't accessible here. */
 	struct jtag_command *cmd = jtag_command_queue;
-	while (debug_level >= LOG_LVL_DEBUG && cmd) {
+	while (debug_level >= LOG_LVL_DEBUG_IO && cmd) {
 		switch (cmd->type) {
 			case JTAG_SCAN:
 				LOG_DEBUG_IO("JTAG %s SCAN to %s",
@@ -969,12 +969,12 @@ int default_interface_jtag_execute_queue(void)
 				for (int i = 0; i < cmd->cmd.scan->num_fields; i++) {
 					struct scan_field *field = cmd->cmd.scan->fields + i;
 					if (field->out_value) {
-						char *str = buf_to_str(field->out_value, field->num_bits, 16);
+						char *str = buf_to_hex_str(field->out_value, field->num_bits);
 						LOG_DEBUG_IO("  %db out: %s", field->num_bits, str);
 						free(str);
 					}
 					if (field->in_value) {
-						char *str = buf_to_str(field->in_value, field->num_bits, 16);
+						char *str = buf_to_hex_str(field->in_value, field->num_bits);
 						LOG_DEBUG_IO("  %db  in: %s", field->num_bits, str);
 						free(str);
 					}
@@ -1436,7 +1436,7 @@ static int jtag_validate_ircapture(void)
 	/* verify the '11' sentinel we wrote is returned at the end */
 	val = buf_get_u64(ir_test, chain_pos, 2);
 	if (val != 0x3) {
-		char *cbuf = buf_to_str(ir_test, total_ir_length, 16);
+		char *cbuf = buf_to_hex_str(ir_test, total_ir_length);
 
 		LOG_ERROR("IR capture error at bit %d, saw 0x%s not 0x...3",
 			chain_pos, cbuf);
diff --git a/src/jtag/drivers/jtag_vpi.c b/src/jtag/drivers/jtag_vpi.c
index a5f441cc7..789d3a466 100644
--- a/src/jtag/drivers/jtag_vpi.c
+++ b/src/jtag/drivers/jtag_vpi.c
@@ -103,11 +103,10 @@ static int jtag_vpi_send_cmd(struct vpi_cmd *vpi)
 	if (LOG_LEVEL_IS(LOG_LVL_DEBUG_IO)) {
 		if (vpi->nb_bits > 0) {
 			/* command with a non-empty data payload */
-			char *char_buf = buf_to_str(vpi->buffer_out,
+			char *char_buf = buf_to_hex_str(vpi->buffer_out,
 					(vpi->nb_bits > DEBUG_JTAG_IOZ)
 						? DEBUG_JTAG_IOZ
-						: vpi->nb_bits,
-					16);
+						: vpi->nb_bits);
 			LOG_DEBUG_IO("sending JTAG VPI cmd: cmd=%s, "
 					"length=%" PRIu32 ", "
 					"nb_bits=%" PRIu32 ", "
@@ -328,9 +327,8 @@ static int jtag_vpi_queue_tdi_xfer(uint8_t *bits, int nb_bits, int tap_shift)
 
 	/* Optional low-level JTAG debug */
 	if (LOG_LEVEL_IS(LOG_LVL_DEBUG_IO)) {
-		char *char_buf = buf_to_str(vpi.buffer_in,
-				(nb_bits > DEBUG_JTAG_IOZ) ? DEBUG_JTAG_IOZ : nb_bits,
-				16);
+		char *char_buf = buf_to_hex_str(vpi.buffer_in,
+				(nb_bits > DEBUG_JTAG_IOZ) ? DEBUG_JTAG_IOZ : nb_bits);
 		LOG_DEBUG_IO("recvd JTAG VPI data: nb_bits=%d, buf_in=0x%s%s",
 			nb_bits, char_buf, (nb_bits > DEBUG_JTAG_IOZ) ? "(...)" : "");
 		free(char_buf);
diff --git a/src/jtag/tcl.c b/src/jtag/tcl.c
index 8b76bff07..1335c2917 100644
--- a/src/jtag/tcl.c
+++ b/src/jtag/tcl.c
@@ -204,7 +204,7 @@ static int Jim_Command_drscan(Jim_Interp *interp, int argc, Jim_Obj *const *args
 		char *str;
 
 		Jim_GetLong(interp, args[i], &bits);
-		str = buf_to_str(fields[field_count].in_value, bits, 16);
+		str = buf_to_hex_str(fields[field_count].in_value, bits);
 		free(fields[field_count].in_value);
 
 		Jim_ListAppendElement(interp, list, Jim_NewStringObj(interp, str, strlen(str)));
diff --git a/src/target/target.c b/src/target/target.c
index 4ef5ee19e..affee03b9 100644
--- a/src/target/target.c
+++ b/src/target/target.c
@@ -2897,8 +2897,8 @@ COMMAND_HANDLER(handle_reg_command)
 					continue;
 				/* only print cached values if they are valid */
 				if (reg->valid) {
-					value = buf_to_str(reg->value,
-							reg->size, 16);
+					value = buf_to_hex_str(reg->value,
+							reg->size);
 					command_print(CMD,
 							"(%i) %s (/%" PRIu32 "): 0x%s%s",
 							count, reg->name,
@@ -2965,7 +2965,7 @@ COMMAND_HANDLER(handle_reg_command)
 
 		if (reg->valid == 0)
 			reg->type->get(reg);
-		value = buf_to_str(reg->value, reg->size, 16);
+		value = buf_to_hex_str(reg->value, reg->size);
 		command_print(CMD, "%s (/%i): 0x%s", reg->name, (int)(reg->size), value);
 		free(value);
 		return ERROR_OK;
@@ -2980,7 +2980,7 @@ COMMAND_HANDLER(handle_reg_command)
 
 		reg->type->set(reg, buf);
 
-		value = buf_to_str(reg->value, reg->size, 16);
+		value = buf_to_hex_str(reg->value, reg->size);
 		command_print(CMD, "%s (/%i): 0x%s", reg->name, (int)(reg->size), value);
 		free(value);
 
@@ -3744,8 +3744,8 @@ static int handle_bp_command_list(struct command_invocation *cmd)
 	struct breakpoint *breakpoint = target->breakpoints;
 	while (breakpoint) {
 		if (breakpoint->type == BKPT_SOFT) {
-			char *buf = buf_to_str(breakpoint->orig_instr,
-					breakpoint->length, 16);
+			char *buf = buf_to_hex_str(breakpoint->orig_instr,
+					breakpoint->length);
 			command_print(cmd, "IVA breakpoint: " TARGET_ADDR_FMT ", 0x%x, %i, 0x%s",
 					breakpoint->address,
 					breakpoint->length,