jtag_vpi: multiple improvements

- Fix: Proper handling of read_socket() and write_socket()
in case of "partial" read/write.

- Added low-level JTAG IO debug capability (_DEBUG_JTAG_IO_)

- Zero-fill packet buffers, avoid sending pieces of uninitialized
memory over the network (memset struct vpi_cmd)

- Use close_socket() instead of close() - needed for Win32

- Fixed usage messages of jtag_vpi_command_handlers

Change-Id: I8bd19bc5c9512fe8e798600212e8a95213f50f5b
Signed-off-by: Jan Matyas <matyas@codasip.com>
Reviewed-on: http://openocd.zylin.com/5177
Tested-by: jenkins
Reviewed-by: Andreas Fritiofson <andreas.fritiofson@gmail.com>
Reviewed-by: Tomas Vanek <vanekt@fbl.cz>

src/helper/log.c

@@ -454,3 +454,28 @@ void busy_sleep(uint64_t ms)
 		 */
 	}
 }
+
+/* Maximum size of socket error message retreived from operation system */
+#define MAX_SOCKET_ERR_MSG_LENGTH 256
+
+/* Provide log message for the last socket error.
+   Uses errno on *nix and WSAGetLastError() on Windows */
+void log_socket_error(const char *socket_desc)
+{
+	int error_code;
+#ifdef _WIN32
+	error_code = WSAGetLastError();
+	char error_message[MAX_SOCKET_ERR_MSG_LENGTH];
+	error_message[0] = '\0';
+	DWORD retval = FormatMessage(FORMAT_MESSAGE_FROM_SYSTEM, NULL, error_code, 0,
+		error_message, MAX_SOCKET_ERR_MSG_LENGTH, NULL);
+	error_message[MAX_SOCKET_ERR_MSG_LENGTH - 1] = '\0';
+	const bool have_message = (retval != 0) && (error_message[0] != '\0');
+	LOG_ERROR("Error on socket '%s': WSAGetLastError==%d%s%s.", socket_desc, error_code,
+		(have_message ? ", message: " : ""),
+		(have_message ? error_message : ""));
+#else
+	error_code = errno;
+	LOG_ERROR("Error on socket '%s': errno==%d, message: %s.", socket_desc, error_code, strerror(error_code));
+#endif
+}

src/helper/log.h

@@ -82,6 +82,8 @@ void kept_alive(void);
 void alive_sleep(uint64_t ms);
 void busy_sleep(uint64_t ms);
 
+void log_socket_error(const char *socket_desc);
+
 typedef void (*log_callback_fn)(void *priv, const char *file, unsigned line,
 		const char *function, const char *string);
 

src/jtag/drivers/jtag_vpi.c

@@ -33,6 +33,8 @@
 #include <netinet/tcp.h>
 #endif
 
+#include <string.h>
+
 #define NO_TAP_SHIFT	0
 #define TAP_SHIFT	1
 
@@ -71,8 +73,58 @@ struct vpi_cmd {
 	};
 };
 
+static char *jtag_vpi_cmd_to_str(int cmd_num)
+{
+	switch (cmd_num) {
+	case CMD_RESET:
+		return "CMD_RESET";
+	case CMD_TMS_SEQ:
+		return "CMD_TMS_SEQ";
+	case CMD_SCAN_CHAIN:
+		return "CMD_SCAN_CHAIN";
+	case CMD_SCAN_CHAIN_FLIP_TMS:
+		return "CMD_SCAN_CHAIN_FLIP_TMS";
+	case CMD_STOP_SIMU:
+		return "CMD_STOP_SIMU";
+	default:
+		return "<unknown>";
+	}
+}
+
 static int jtag_vpi_send_cmd(struct vpi_cmd *vpi)
 {
+	int retval;
+
+	/* Optional low-level JTAG debug */
+	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,
+					(vpi->nb_bits > DEBUG_JTAG_IOZ)
+						? DEBUG_JTAG_IOZ
+						: vpi->nb_bits,
+					16);
+			LOG_DEBUG_IO("sending JTAG VPI cmd: cmd=%s, "
+					"length=%" PRIu32 ", "
+					"nb_bits=%" PRIu32 ", "
+					"buf_out=0x%s%s",
+					jtag_vpi_cmd_to_str(vpi->cmd),
+					vpi->length,
+					vpi->nb_bits,
+					char_buf,
+					(vpi->nb_bits > DEBUG_JTAG_IOZ) ? "(...)" : "");
+			free(char_buf);
+		} else {
+			/* command without data payload */
+			LOG_DEBUG_IO("sending JTAG VPI cmd: cmd=%s, "
+					"length=%" PRIu32 ", "
+					"nb_bits=%" PRIu32,
+					jtag_vpi_cmd_to_str(vpi->cmd),
+					vpi->length,
+					vpi->nb_bits);
+		}
+	}
+
 	/* Use little endian when transmitting/receiving jtag_vpi cmds.
 	   The choice of little endian goes against usual networking conventions
 	   but is intentional to remain compatible with most older OpenOCD builds
@@ -81,18 +133,67 @@ static int jtag_vpi_send_cmd(struct vpi_cmd *vpi)
 	h_u32_to_le(vpi->length_buf, vpi->length);
 	h_u32_to_le(vpi->nb_bits_buf, vpi->nb_bits);
 
-	int retval = write_socket(sockfd, vpi, sizeof(struct vpi_cmd));
+retry_write:
-	if (retval <= 0)
+	retval = write_socket(sockfd, vpi, sizeof(struct vpi_cmd));
-		return ERROR_FAIL;
 
+	if (retval < 0) {
+		/* Account for the case when socket write is interrupted. */
+#ifdef _WIN32
+		int wsa_err = WSAGetLastError();
+		if (wsa_err == WSAEINTR)
+			goto retry_write;
+#else
+		if (errno == EINTR)
+			goto retry_write;
+#endif
+		/* Otherwise this is an error using the socket, most likely fatal
+		   for the connection. B*/
+		log_socket_error("jtag_vpi xmit");
+		/* TODO: Clean way how adapter drivers can report fatal errors
+		   to upper layers of OpenOCD and let it perform an orderly shutdown? */
+		exit(-1);
+	} else if (retval < (int)sizeof(struct vpi_cmd)) {
+		/* This means we could not send all data, which is most likely fatal
+		   for the jtag_vpi connection (the underlying TCP connection likely not
+		   usable anymore) */
+		LOG_ERROR("Could not send all data through jtag_vpi connection.");
+		exit(-1);
+	}
+
+	/* Otherwise the packet has been sent successfully. */
 	return ERROR_OK;
 }
 
 static int jtag_vpi_receive_cmd(struct vpi_cmd *vpi)
 {
-	int retval = read_socket(sockfd, vpi, sizeof(struct vpi_cmd));
+	unsigned bytes_buffered = 0;
-	if (retval < (int)sizeof(struct vpi_cmd))
+	while (bytes_buffered < sizeof(struct vpi_cmd)) {
-		return ERROR_FAIL;
+		int bytes_to_receive = sizeof(struct vpi_cmd) - bytes_buffered;
+		int retval = read_socket(sockfd, ((char *)vpi) + bytes_buffered, bytes_to_receive);
+		if (retval < 0) {
+#ifdef _WIN32
+			int wsa_err = WSAGetLastError();
+			if (wsa_err == WSAEINTR) {
+				/* socket read interrupted by WSACancelBlockingCall() */
+				continue;
+			}
+#else
+			if (errno == EINTR) {
+				/* socket read interrupted by a signal */
+				continue;
+			}
+#endif
+			/* Otherwise, this is an error when accessing the socket. */
+			log_socket_error("jtag_vpi recv");
+			exit(-1);
+		} else if (retval == 0) {
+			/* Connection closed by the other side */
+			LOG_ERROR("Connection prematurely closed by jtag_vpi server.");
+			exit(-1);
+		}
+		/* Otherwise, we have successfully received some data */
+		bytes_buffered += retval;
+	}
 
 	/* Use little endian when transmitting/receiving jtag_vpi cmds. */
 	vpi->cmd = le_to_h_u32(vpi->cmd_buf);
@@ -110,6 +211,7 @@ static int jtag_vpi_receive_cmd(struct vpi_cmd *vpi)
 static int jtag_vpi_reset(int trst, int srst)
 {
 	struct vpi_cmd vpi;
+	memset(&vpi, 0, sizeof(struct vpi_cmd));
 
 	vpi.cmd = CMD_RESET;
 	vpi.length = 0;
@@ -132,6 +234,7 @@ static int jtag_vpi_tms_seq(const uint8_t *bits, int nb_bits)
 	struct vpi_cmd vpi;
 	int nb_bytes;
 
+	memset(&vpi, 0, sizeof(struct vpi_cmd));
 	nb_bytes = DIV_ROUND_UP(nb_bits, 8);
 
 	vpi.cmd = CMD_TMS_SEQ;
@@ -199,6 +302,8 @@ static int jtag_vpi_queue_tdi_xfer(uint8_t *bits, int nb_bits, int tap_shift)
 	struct vpi_cmd vpi;
 	int nb_bytes = DIV_ROUND_UP(nb_bits, 8);
 
+	memset(&vpi, 0, sizeof(struct vpi_cmd));
+
 	vpi.cmd = tap_shift ? CMD_SCAN_CHAIN_FLIP_TMS : CMD_SCAN_CHAIN;
 
 	if (bits)
@@ -217,6 +322,16 @@ static int jtag_vpi_queue_tdi_xfer(uint8_t *bits, int nb_bits, int tap_shift)
 	if (retval != ERROR_OK)
 		return retval;
 
+	/* 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);
+		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);
+	}
+
 	if (bits)
 		memcpy(bits, vpi.buffer_in, nb_bytes);
 
@@ -464,7 +579,7 @@ static int jtag_vpi_init(void)
 static int jtag_vpi_quit(void)
 {
 	free(server_address);
-	return close(sockfd);
+	return close_socket(sockfd);
 }
 
 COMMAND_HANDLER(jtag_vpi_set_port)
@@ -500,14 +615,14 @@ static const struct command_registration jtag_vpi_command_handlers[] = {
 		.handler = &jtag_vpi_set_port,
 		.mode = COMMAND_CONFIG,
 		.help = "set the port of the VPI server",
-		.usage = "description_string",
+		.usage = "tcp_port_num",
 	},
 	{
 		.name = "jtag_vpi_set_address",
 		.handler = &jtag_vpi_set_address,
 		.mode = COMMAND_CONFIG,
 		.help = "set the address of the VPI server",
-		.usage = "description_string",
+		.usage = "ipv4_addr",
 	},
 	COMMAND_REGISTRATION_DONE
 };