Add wall clock timeout warning to mpsse_flush()
[openocd.git] / src / jtag / drivers / mpsse.c
index 924c974502af9ac8b3f5acfdfcd37077642f7a2d..7488d9dd877c65a97a8b88057a3299d25001e3de 100644 (file)
@@ -22,6 +22,7 @@
 
 #include "mpsse.h"
 #include "helper/log.h"
+#include "helper/time_support.h"
 #include <libusb.h>
 
 /* Compatibility define for older libusb-1.0 */
 #define LIBUSB_CALL
 #endif
 
-#ifdef _DEBUG_JTAG_IO_
-#define DEBUG_IO(expr...) LOG_DEBUG(expr)
 #define DEBUG_PRINT_BUF(buf, len) \
        do { \
-               char buf_string[32 * 3 + 1]; \
-               int buf_string_pos = 0; \
-               for (int i = 0; i < len; i++) { \
-                       buf_string_pos += sprintf(buf_string + buf_string_pos, " %02x", buf[i]); \
-                       if (i % 32 == 32 - 1) { \
-                               LOG_DEBUG("%s", buf_string); \
-                               buf_string_pos = 0; \
+               if (LOG_LEVEL_IS(LOG_LVL_DEBUG_IO)) { \
+                       char buf_string[32 * 3 + 1]; \
+                       int buf_string_pos = 0; \
+                       for (int i = 0; i < len; i++) { \
+                               buf_string_pos += sprintf(buf_string + buf_string_pos, " %02x", buf[i]); \
+                               if (i % 32 == 32 - 1) { \
+                                       LOG_DEBUG_IO("%s", buf_string); \
+                                       buf_string_pos = 0; \
+                               } \
                        } \
+                       if (buf_string_pos > 0) \
+                               LOG_DEBUG_IO("%s", buf_string);\
                } \
-               if (buf_string_pos > 0) \
-                       LOG_DEBUG("%s", buf_string);\
        } while (0)
-#else
-#define DEBUG_IO(expr...) do {} while (0)
-#define DEBUG_PRINT_BUF(buf, len) do {} while (0)
-#endif
 
 #define FTDI_DEVICE_OUT_REQTYPE (LIBUSB_REQUEST_TYPE_VENDOR | LIBUSB_RECIPIENT_DEVICE)
 #define FTDI_DEVICE_IN_REQTYPE (0x80 | LIBUSB_REQUEST_TYPE_VENDOR | LIBUSB_RECIPIENT_DEVICE)
@@ -120,7 +117,7 @@ static bool device_location_equal(libusb_device *device, const char *location)
 
        LOG_DEBUG("device path has %i steps", path_len);
 
-       ptr = strtok(loc, ":");
+       ptr = strtok(loc, "-:");
        if (ptr == NULL) {
                LOG_DEBUG("no ':' in path");
                goto done;
@@ -132,7 +129,7 @@ static bool device_location_equal(libusb_device *device, const char *location)
 
        path_step = 0;
        while (path_step < 7) {
-               ptr = strtok(NULL, ",");
+               ptr = strtok(NULL, ".,");
                if (ptr == NULL) {
                        LOG_DEBUG("no more tokens in path at step %i", path_step);
                        break;
@@ -335,7 +332,13 @@ struct mpsse_ctx *mpsse_open(const uint16_t *vid, const uint16_t *pid, const cha
        ctx->write_size = 16384;
        ctx->read_chunk = malloc(ctx->read_chunk_size);
        ctx->read_buffer = malloc(ctx->read_size);
-       ctx->write_buffer = malloc(ctx->write_size);
+
+       /* Use calloc to make valgrind happy: buffer_write() sets payload
+        * on bit basis, so some bits can be left uninitialized in write_buffer.
+        * Although this is perfectly ok with MPSSE, valgrind reports
+        * Syscall param ioctl(USBDEVFS_SUBMITURB).buffer points to uninitialised byte(s) */
+       ctx->write_buffer = calloc(1, ctx->write_size);
+
        if (!ctx->read_chunk || !ctx->read_buffer || !ctx->write_buffer)
                goto error;
 
@@ -452,7 +455,7 @@ static unsigned buffer_read_space(struct mpsse_ctx *ctx)
 
 static void buffer_write_byte(struct mpsse_ctx *ctx, uint8_t data)
 {
-       DEBUG_IO("%02x", data);
+       LOG_DEBUG_IO("%02x", data);
        assert(ctx->write_count < ctx->write_size);
        ctx->write_buffer[ctx->write_count++] = data;
 }
@@ -460,7 +463,7 @@ static void buffer_write_byte(struct mpsse_ctx *ctx, uint8_t data)
 static unsigned buffer_write(struct mpsse_ctx *ctx, const uint8_t *out, unsigned out_offset,
        unsigned bit_count)
 {
-       DEBUG_IO("%d bits", bit_count);
+       LOG_DEBUG_IO("%d bits", bit_count);
        assert(ctx->write_count + DIV_ROUND_UP(bit_count, 8) <= ctx->write_size);
        bit_copy(ctx->write_buffer + ctx->write_count, 0, out, out_offset, bit_count);
        ctx->write_count += DIV_ROUND_UP(bit_count, 8);
@@ -470,7 +473,7 @@ static unsigned buffer_write(struct mpsse_ctx *ctx, const uint8_t *out, unsigned
 static unsigned buffer_add_read(struct mpsse_ctx *ctx, uint8_t *in, unsigned in_offset,
        unsigned bit_count, unsigned offset)
 {
-       DEBUG_IO("%d bits, offset %d", bit_count, offset);
+       LOG_DEBUG_IO("%d bits, offset %d", bit_count, offset);
        assert(ctx->read_count + DIV_ROUND_UP(bit_count, 8) <= ctx->read_size);
        bit_copy_queued(&ctx->read_queue, in, in_offset, ctx->read_buffer + ctx->read_count, offset,
                bit_count);
@@ -494,10 +497,10 @@ void mpsse_clock_data(struct mpsse_ctx *ctx, const uint8_t *out, unsigned out_of
        unsigned in_offset, unsigned length, uint8_t mode)
 {
        /* TODO: Fix MSB first modes */
-       DEBUG_IO("%s%s %d bits", in ? "in" : "", out ? "out" : "", length);
+       LOG_DEBUG_IO("%s%s %d bits", in ? "in" : "", out ? "out" : "", length);
 
        if (ctx->retval != ERROR_OK) {
-               DEBUG_IO("Ignoring command due to previous error");
+               LOG_DEBUG_IO("Ignoring command due to previous error");
                return;
        }
 
@@ -570,11 +573,11 @@ void mpsse_clock_tms_cs_out(struct mpsse_ctx *ctx, const uint8_t *out, unsigned
 void mpsse_clock_tms_cs(struct mpsse_ctx *ctx, const uint8_t *out, unsigned out_offset, uint8_t *in,
        unsigned in_offset, unsigned length, bool tdi, uint8_t mode)
 {
-       DEBUG_IO("%sout %d bits, tdi=%d", in ? "in" : "", length, tdi);
+       LOG_DEBUG_IO("%sout %d bits, tdi=%d", in ? "in" : "", length, tdi);
        assert(out);
 
        if (ctx->retval != ERROR_OK) {
-               DEBUG_IO("Ignoring command due to previous error");
+               LOG_DEBUG_IO("Ignoring command due to previous error");
                return;
        }
 
@@ -620,10 +623,10 @@ void mpsse_clock_tms_cs(struct mpsse_ctx *ctx, const uint8_t *out, unsigned out_
 
 void mpsse_set_data_bits_low_byte(struct mpsse_ctx *ctx, uint8_t data, uint8_t dir)
 {
-       DEBUG_IO("-");
+       LOG_DEBUG_IO("-");
 
        if (ctx->retval != ERROR_OK) {
-               DEBUG_IO("Ignoring command due to previous error");
+               LOG_DEBUG_IO("Ignoring command due to previous error");
                return;
        }
 
@@ -637,10 +640,10 @@ void mpsse_set_data_bits_low_byte(struct mpsse_ctx *ctx, uint8_t data, uint8_t d
 
 void mpsse_set_data_bits_high_byte(struct mpsse_ctx *ctx, uint8_t data, uint8_t dir)
 {
-       DEBUG_IO("-");
+       LOG_DEBUG_IO("-");
 
        if (ctx->retval != ERROR_OK) {
-               DEBUG_IO("Ignoring command due to previous error");
+               LOG_DEBUG_IO("Ignoring command due to previous error");
                return;
        }
 
@@ -654,10 +657,10 @@ void mpsse_set_data_bits_high_byte(struct mpsse_ctx *ctx, uint8_t data, uint8_t
 
 void mpsse_read_data_bits_low_byte(struct mpsse_ctx *ctx, uint8_t *data)
 {
-       DEBUG_IO("-");
+       LOG_DEBUG_IO("-");
 
        if (ctx->retval != ERROR_OK) {
-               DEBUG_IO("Ignoring command due to previous error");
+               LOG_DEBUG_IO("Ignoring command due to previous error");
                return;
        }
 
@@ -670,10 +673,10 @@ void mpsse_read_data_bits_low_byte(struct mpsse_ctx *ctx, uint8_t *data)
 
 void mpsse_read_data_bits_high_byte(struct mpsse_ctx *ctx, uint8_t *data)
 {
-       DEBUG_IO("-");
+       LOG_DEBUG_IO("-");
 
        if (ctx->retval != ERROR_OK) {
-               DEBUG_IO("Ignoring command due to previous error");
+               LOG_DEBUG_IO("Ignoring command due to previous error");
                return;
        }
 
@@ -688,7 +691,7 @@ static void single_byte_boolean_helper(struct mpsse_ctx *ctx, bool var, uint8_t
        uint8_t val_if_false)
 {
        if (ctx->retval != ERROR_OK) {
-               DEBUG_IO("Ignoring command due to previous error");
+               LOG_DEBUG_IO("Ignoring command due to previous error");
                return;
        }
 
@@ -709,7 +712,7 @@ void mpsse_set_divisor(struct mpsse_ctx *ctx, uint16_t divisor)
        LOG_DEBUG("%d", divisor);
 
        if (ctx->retval != ERROR_OK) {
-               DEBUG_IO("Ignoring command due to previous error");
+               LOG_DEBUG_IO("Ignoring command due to previous error");
                return;
        }
 
@@ -811,7 +814,7 @@ static LIBUSB_CALL void read_cb(struct libusb_transfer *transfer)
                }
        }
 
-       DEBUG_IO("raw chunk %d, transferred %d of %d", transfer->actual_length, res->transferred,
+       LOG_DEBUG_IO("raw chunk %d, transferred %d of %d", transfer->actual_length, res->transferred,
                ctx->read_count);
 
        if (!res->done)
@@ -826,7 +829,7 @@ static LIBUSB_CALL void write_cb(struct libusb_transfer *transfer)
 
        res->transferred += transfer->actual_length;
 
-       DEBUG_IO("transferred %d of %d", res->transferred, ctx->write_count);
+       LOG_DEBUG_IO("transferred %d of %d", res->transferred, ctx->write_count);
 
        DEBUG_PRINT_BUF(transfer->buffer, transfer->actual_length);
 
@@ -845,13 +848,13 @@ int mpsse_flush(struct mpsse_ctx *ctx)
        int retval = ctx->retval;
 
        if (retval != ERROR_OK) {
-               DEBUG_IO("Ignoring flush due to previous error");
+               LOG_DEBUG_IO("Ignoring flush due to previous error");
                assert(ctx->write_count == 0 && ctx->read_count == 0);
                ctx->retval = ERROR_OK;
                return retval;
        }
 
-       DEBUG_IO("write %d%s, read %d", ctx->write_count, ctx->read_count ? "+1" : "",
+       LOG_DEBUG_IO("write %d%s, read %d", ctx->write_count, ctx->read_count ? "+1" : "",
                        ctx->read_count);
        assert(ctx->write_count > 0 || ctx->read_count == 0); /* No read data without write data */
 
@@ -886,6 +889,8 @@ int mpsse_flush(struct mpsse_ctx *ctx)
        }
 
        /* Polling loop, more or less taken from libftdi */
+       int64_t start = timeval_ms();
+       int64_t warn_after = 2000;
        while (!write_result.done || !read_result.done) {
                struct timeval timeout_usb;
 
@@ -908,6 +913,13 @@ int mpsse_flush(struct mpsse_ctx *ctx)
                                        break;
                        }
                }
+
+               int64_t now = timeval_ms();
+               if (now - start > warn_after) {
+                       LOG_WARNING("Haven't made progress in mpsse_flush() for %" PRId64
+                                       "ms.", now - start);
+                       warn_after *= 2;
+               }
        }
 
 error_check:

Linking to existing account procedure

If you already have an account and want to add another login method you MUST first sign in with your existing account and then change URL to read https://review.openocd.org/login/?link to get to this page again but this time it'll work for linking. Thank you.

SSH host keys fingerprints

1024 SHA256:YKx8b7u5ZWdcbp7/4AeXNaqElP49m6QrwfXaqQGJAOk gerrit-code-review@openocd.zylin.com (DSA)
384 SHA256:jHIbSQa4REvwCFG4cq5LBlBLxmxSqelQPem/EXIrxjk gerrit-code-review@openocd.org (ECDSA)
521 SHA256:UAOPYkU9Fjtcao0Ul/Rrlnj/OsQvt+pgdYSZ4jOYdgs gerrit-code-review@openocd.org (ECDSA)
256 SHA256:A13M5QlnozFOvTllybRZH6vm7iSt0XLxbA48yfc2yfY gerrit-code-review@openocd.org (ECDSA)
256 SHA256:spYMBqEYoAOtK7yZBrcwE8ZpYt6b68Cfh9yEVetvbXg gerrit-code-review@openocd.org (ED25519)
+--[ED25519 256]--+
|=..              |
|+o..   .         |
|*.o   . .        |
|+B . . .         |
|Bo. = o S        |
|Oo.+ + =         |
|oB=.* = . o      |
| =+=.+   + E     |
|. .=o   . o      |
+----[SHA256]-----+
2048 SHA256:0Onrb7/PHjpo6iVZ7xQX2riKN83FJ3KGU0TvI0TaFG4 gerrit-code-review@openocd.zylin.com (RSA)