log USB timeouts in API stats

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,30 @@ 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[0].count == 0 &&
+			cgpu->usbinfo.usb_tmo[0].count == 0) {
+				snprintf(details, sizeof(details),
+					 "%"PRIu64" 0", cgpu->usbinfo.tmo_count);
+		} else {
+			snprintf(details, sizeof(details),
+				 "%"PRIu64" %d=%d/%"PRIu64"/%"PRIu64
+				 " %d=%d/%"PRIu64"/%"PRIu64
+				 " %d=%d/%"PRIu64"/%"PRIu64" ",
+				 cgpu->usbinfo.tmo_count,
+				 USB_TMO_0, cgpu->usbinfo.usb_tmo[0].count,
+				 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].total_over,
+				 cgpu->usbinfo.usb_tmo[1].total_tmo,
+				 USB_TMO_2, cgpu->usbinfo.usb_tmo[2].count,
+				 cgpu->usbinfo.usb_tmo[2].total_over,
+				 cgpu->usbinfo.usb_tmo[2].total_tmo);
+		}
+
+		root = api_add_string(root, "USB tmo", details, true);
 #endif
 	}
 

usbutils.c

@@ -460,9 +460,6 @@ static int next_stat = USB_NOSTAT;
 
 #define SECTOMS(s) ((int)((s) * 1000))
 
-// timeout checks are only done when stats are enabled
-#define TIMEOUT_OVER_MS 500
-
 #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_)
@@ -2128,17 +2125,29 @@ static void stats(struct cgpu_info *cgpu, struct timeval *tv_start, struct timev
 {
 	struct cg_usb_stats_details *details;
 	double diff;
-	int item, elapsedms;
+	int item, extrams;
 
 	if (cgpu->usbinfo.usbstat < 1)
 		newstats(cgpu);
 
+	cgpu->usbinfo.tmo_count++;
+
 	// timeout checks are only done when stats are enabled
-	elapsedms = SECTOMS(tdiff(tv_finish, tv_start));
+	extrams = SECTOMS(tdiff(tv_finish, tv_start)) - timeout;
-	if (elapsedms > (timeout + TIMEOUT_OVER_MS)) {
+	if (extrams >= USB_TMO_0) {
-		applog(LOG_ERR, "%s%i: TIMEOUT %s took %dms but was %dms",
+		int offset = 0;
-				cgpu->drv->name, cgpu->device_id,
+
-				usb_cmdname(cmd), elapsedms, timeout) ;
+		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), extrams+timeout, 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;
 	}
 
 	details = &(usb_stats[cgpu->usbinfo.usbstat - 1].details[cmd * 2 + seq]);

usbutils.h

@@ -186,6 +186,17 @@ 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;
+	uint64_t total_over;
+	uint64_t total_tmo;
+};
+
 struct cg_usb_info {
 	uint8_t bus_number;
 	uint8_t device_address;
@@ -224,6 +235,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 {