diff --git a/api.c b/api.c index 8c29bf99..5d24771e 100644 --- a/api.c +++ b/api.c @@ -3023,7 +3023,7 @@ static int itemstats(struct io_data *io_data, int i, char *id, struct cgminer_st if (cgpu) { #ifdef USE_USBUTILS - char details[128]; + char details[256]; if (cgpu->usbinfo.pipe_count) snprintf(details, sizeof(details), @@ -3046,6 +3046,36 @@ static int itemstats(struct io_data *io_data, int i, char *id, struct cgminer_st cgpu->usbinfo.total_write_delay); root = api_add_string(root, "USB Delay", details, true); + + if (cgpu->usbinfo.usb_tmo[0].count == 0 && + cgpu->usbinfo.usb_tmo[1].count == 0 && + cgpu->usbinfo.usb_tmo[2].count == 0) { + snprintf(details, sizeof(details), + "%"PRIu64" 0", cgpu->usbinfo.tmo_count); + } else { + snprintf(details, sizeof(details), + "%"PRIu64" %d=%d/%d/%d/%"PRIu64"/%"PRIu64 + " %d=%d/%d/%d/%"PRIu64"/%"PRIu64 + " %d=%d/%d/%d/%"PRIu64"/%"PRIu64" ", + cgpu->usbinfo.tmo_count, + USB_TMO_0, cgpu->usbinfo.usb_tmo[0].count, + cgpu->usbinfo.usb_tmo[0].min_tmo, + cgpu->usbinfo.usb_tmo[0].max_tmo, + cgpu->usbinfo.usb_tmo[0].total_over, + cgpu->usbinfo.usb_tmo[0].total_tmo, + USB_TMO_1, cgpu->usbinfo.usb_tmo[1].count, + cgpu->usbinfo.usb_tmo[1].min_tmo, + cgpu->usbinfo.usb_tmo[1].max_tmo, + cgpu->usbinfo.usb_tmo[1].total_over, + cgpu->usbinfo.usb_tmo[1].total_tmo, + USB_TMO_2, cgpu->usbinfo.usb_tmo[2].count, + cgpu->usbinfo.usb_tmo[2].min_tmo, + cgpu->usbinfo.usb_tmo[2].max_tmo, + cgpu->usbinfo.usb_tmo[2].total_over, + cgpu->usbinfo.usb_tmo[2].total_tmo); + } + + root = api_add_string(root, "USB tmo", details, true); #endif } diff --git a/usbutils.c b/usbutils.c index 25e8f02b..a0dbbe3c 100644 --- a/usbutils.c +++ b/usbutils.c @@ -458,14 +458,17 @@ struct cg_usb_stats { static struct cg_usb_stats *usb_stats = NULL; static int next_stat = USB_NOSTAT; -#define USB_STATS(sgpu, sta, fin, err, mode, cmd, seq) \ - stats(cgpu, sta, fin, err, mode, cmd, seq) -#define STATS_TIMEVAL(tv) cgtime(tv) -#define USB_REJECT(sgpu, mode) rejected_inc(sgpu, mode) +#define SECTOMS(s) ((int)((s) * 1000)) + +#define USB_STATS(sgpu_, sta_, fin_, err_, mode_, cmd_, seq_, tmo_) \ + stats(sgpu_, sta_, fin_, err_, mode_, cmd_, seq_, tmo_) +#define STATS_TIMEVAL(tv_) cgtime(tv_) +#define USB_REJECT(sgpu_, mode_) rejected_inc(sgpu_, mode_) + #else -#define USB_STATS(sgpu, sta, fin, err, mode, cmd, seq) -#define STATS_TIMEVAL(tv) -#define USB_REJECT(sgpu, mode) +#define USB_STATS(sgpu_, sta_, fin_, err_, mode_, cmd_, seq_, tmo_) +#define STATS_TIMEVAL(tv_) +#define USB_REJECT(sgpu_, mode_) #endif // DO_USB_STATS @@ -2118,15 +2121,45 @@ void update_usb_stats(__maybe_unused struct cgpu_info *cgpu) } #if DO_USB_STATS -static void stats(struct cgpu_info *cgpu, struct timeval *tv_start, struct timeval *tv_finish, int err, int mode, enum usb_cmds cmd, int seq) +static void stats(struct cgpu_info *cgpu, struct timeval *tv_start, struct timeval *tv_finish, int err, int mode, enum usb_cmds cmd, int seq, int timeout) { struct cg_usb_stats_details *details; double diff; - int item; + int item, extrams; if (cgpu->usbinfo.usbstat < 1) newstats(cgpu); + cgpu->usbinfo.tmo_count++; + + // timeout checks are only done when stats are enabled + extrams = SECTOMS(tdiff(tv_finish, tv_start)) - timeout; + if (extrams >= USB_TMO_0) { + uint32_t totms = (uint32_t)(timeout + extrams); + int offset = 0; + + if (extrams >= USB_TMO_2) { + applog(LOG_ERR, "%s%i: TIMEOUT %s took %dms but was %dms", + cgpu->drv->name, cgpu->device_id, + usb_cmdname(cmd), totms, timeout) ; + offset = 2; + } else if (extrams >= USB_TMO_1) + offset = 1; + + cgpu->usbinfo.usb_tmo[offset].count++; + cgpu->usbinfo.usb_tmo[offset].total_over += extrams; + cgpu->usbinfo.usb_tmo[offset].total_tmo += timeout; + if (cgpu->usbinfo.usb_tmo[offset].min_tmo == 0) { + cgpu->usbinfo.usb_tmo[offset].min_tmo = totms; + cgpu->usbinfo.usb_tmo[offset].max_tmo = totms; + } else { + if (cgpu->usbinfo.usb_tmo[offset].min_tmo > totms) + cgpu->usbinfo.usb_tmo[offset].min_tmo = totms; + if (cgpu->usbinfo.usb_tmo[offset].max_tmo < totms) + cgpu->usbinfo.usb_tmo[offset].max_tmo = totms; + } + } + details = &(usb_stats[cgpu->usbinfo.usbstat - 1].details[cmd * 2 + seq]); details->modes |= mode; @@ -2234,7 +2267,7 @@ usb_bulk_transfer(struct libusb_device_handle *dev_handle, errn = errno; cg_runlock(&cgusb_fd_lock); STATS_TIMEVAL(&tv_finish); - USB_STATS(cgpu, &tv_start, &tv_finish, err, mode, cmd, seq); + USB_STATS(cgpu, &tv_start, &tv_finish, err, mode, cmd, seq, timeout); if (err < 0) applog(LOG_DEBUG, "%s%i: %s (amt=%d err=%d ern=%d)", @@ -2261,7 +2294,7 @@ usb_bulk_transfer(struct libusb_device_handle *dev_handle, errn = errno; cg_runlock(&cgusb_fd_lock); STATS_TIMEVAL(&tv_finish); - USB_STATS(cgpu, &tv_start, &tv_finish, err, mode, cmd, seq); + USB_STATS(cgpu, &tv_start, &tv_finish, err, mode, cmd, seq, timeout); if (err < 0) applog(LOG_DEBUG, "%s%i: %s (amt=%d err=%d ern=%d)", @@ -2581,7 +2614,6 @@ int _usb_write(struct cgpu_info *cgpu, int ep, char *buf, size_t bufsiz, int *pr } usbdev = cgpu->usbdev; - if (timeout == DEVTIMEOUT) timeout = usbdev->found->timeout; @@ -2670,6 +2702,8 @@ int __usb_transfer(struct cgpu_info *cgpu, uint8_t request_type, uint8_t bReques goto out_; } usbdev = cgpu->usbdev; + if (timeout == DEVTIMEOUT) + timeout = usbdev->found->timeout; USBDEBUG("USB debug: @_usb_transfer() data=%s", bin2hex((unsigned char *)data, (size_t)siz)); @@ -2709,11 +2743,10 @@ int __usb_transfer(struct cgpu_info *cgpu, uint8_t request_type, uint8_t bReques STATS_TIMEVAL(&tv_start); cg_rlock(&cgusb_fd_lock); err = libusb_control_transfer(usbdev->handle, request_type, - bRequest, wValue, wIndex, (unsigned char *)buf, (uint16_t)siz, - timeout == DEVTIMEOUT ? usbdev->found->timeout : timeout); + bRequest, wValue, wIndex, (unsigned char *)buf, (uint16_t)siz, timeout); cg_runlock(&cgusb_fd_lock); STATS_TIMEVAL(&tv_finish); - USB_STATS(cgpu, &tv_start, &tv_finish, err, MODE_CTRL_WRITE, cmd, SEQ0); + USB_STATS(cgpu, &tv_start, &tv_finish, err, MODE_CTRL_WRITE, cmd, SEQ0, timeout); USBDEBUG("USB debug: @_usb_transfer(%s (nodev=%s)) err=%d%s", cgpu->drv->name, bool_str(cgpu->usbinfo.nodev), err, isnodev(err)); @@ -2760,6 +2793,8 @@ int _usb_transfer_read(struct cgpu_info *cgpu, uint8_t request_type, uint8_t bRe goto out_unlock; } usbdev = cgpu->usbdev; + if (timeout == DEVTIMEOUT) + timeout = usbdev->found->timeout; *amount = 0; @@ -2785,11 +2820,10 @@ int _usb_transfer_read(struct cgpu_info *cgpu, uint8_t request_type, uint8_t bRe cg_rlock(&cgusb_fd_lock); err = libusb_control_transfer(usbdev->handle, request_type, bRequest, wValue, wIndex, - (unsigned char *)buf, (uint16_t)bufsiz, - timeout == DEVTIMEOUT ? usbdev->found->timeout : timeout); + (unsigned char *)buf, (uint16_t)bufsiz, timeout); cg_runlock(&cgusb_fd_lock); STATS_TIMEVAL(&tv_finish); - USB_STATS(cgpu, &tv_start, &tv_finish, err, MODE_CTRL_READ, cmd, SEQ0); + USB_STATS(cgpu, &tv_start, &tv_finish, err, MODE_CTRL_READ, cmd, SEQ0, timeout); USBDEBUG("USB debug: @_usb_transfer_read(%s (nodev=%s)) amt/err=%d%s%s%s", cgpu->drv->name, bool_str(cgpu->usbinfo.nodev), err, isnodev(err), err > 0 ? " = " : BLANK, err > 0 ? bin2hex((unsigned char *)buf, (size_t)err) : BLANK); diff --git a/usbutils.h b/usbutils.h index 75f1e511..cc855770 100644 --- a/usbutils.h +++ b/usbutils.h @@ -186,6 +186,19 @@ struct cg_usb_device { #define USB_MAX_READ 8192 +#define USB_TMO_0 50 +#define USB_TMO_1 100 +#define USB_TMO_2 500 +#define USB_TMOS 3 + +struct cg_usb_tmo { + uint32_t count; + uint32_t min_tmo; + uint32_t max_tmo; + uint64_t total_over; + uint64_t total_tmo; +}; + struct cg_usb_info { uint8_t bus_number; uint8_t device_address; @@ -224,6 +237,9 @@ struct cg_usb_info { * multiple of these */ unsigned char bulkbuf[USB_MAX_READ+4]; + + uint64_t tmo_count; + struct cg_usb_tmo usb_tmo[USB_TMOS]; }; enum usb_cmds {