Merge commit '976e27c' into bfgminer

Conflicts:
	miner.c

README

@@ -804,6 +804,13 @@ The list of requests - a (*) means it requires privileged access - and replies a
  restart (*)   none           There is no status section but just a single "RESTART"
                               reply before cgminer restarts
 
+ stats         STATS          Each device or pool that has 1 or more getworks
+                              with a list of stats regarding getwork times
+                              The values returned by this may change in future
+                              versions thus would not normally be displayed
+                              except when trying to determine performance and
+                              issues with pool perforamce
+
 When you enable, disable or restart a GPU or PGA, you will also get Thread messages
 in the BFGMiner status window
 

api.c

@@ -232,6 +232,7 @@ static const char *OSINFO =
 #define _DEVDETAILS	"DEVDETAILS"
 #define _BYE		"BYE"
 #define _RESTART	"RESTART"
+#define _MINESTATS	"STATS"
 
 static const char ISJSON = '{';
 #define JSON0		"{"
@@ -265,6 +266,7 @@ static const char ISJSON = '{';
 #define JSON_BYE	JSON1 _BYE JSON1
 #define JSON_RESTART	JSON1 _RESTART JSON1
 #define JSON_CLOSE	JSON3
+#define JSON_MINESTATS	JSON1 _MINESTATS JSON2
 #define JSON_END	JSON4
 
 static const char *JSON_COMMAND = "command";
@@ -351,6 +353,7 @@ static const char *JSON_PARAMETER = "parameter";
 #define MSG_ACTPOOL 67
 #define MSG_REMPOOL 68
 #define MSG_DEVDETAILS 69
+#define MSG_MINESTATS 70
 
 enum code_severity {
 	SEVERITY_ERR,
@@ -476,6 +479,7 @@ struct CODES {
  { SEVERITY_SUCC,  MSG_REMPOOL, PARAM_BOTH,	"Removed pool %d:'%s'" },
  { SEVERITY_SUCC,  MSG_NOTIFY,	PARAM_NONE,	"Notify" },
  { SEVERITY_SUCC,  MSG_DEVDETAILS,PARAM_NONE,	"Device Details" },
+ { SEVERITY_SUCC,  MSG_MINESTATS,PARAM_NONE,	"CGMiner stats" },
  { SEVERITY_FAIL, 0, 0, NULL }
 };
 
@@ -1973,6 +1977,61 @@ void dosave(__maybe_unused SOCKETTYPE c, char *param, bool isjson)
 	ptr = NULL;
 }
 
+static int itemstats(int i, char *id, struct cgminer_stats *stats, bool isjson)
+{
+	char buf[BUFSIZ];
+
+	if (stats->getwork_calls)
+	{
+		sprintf(buf, isjson
+			? "%s{\"STATS\":%d,\"ID\":\"%s\",\"Elapsed\":%.0f,\"Calls\":%d,\"Wait\":%ld.%06ld,\"Max\":%ld.%06ld,\"Min\":%ld.%06ld}"
+			: "%sSTATS=%d,ID=%s,Elapsed=%.0f,Calls=%d,Wait=%ld.%06ld,Max=%ld.%06ld,Min=%ld.%06ld" SEPSTR,
+			(isjson && (i > 0)) ? COMMA : BLANK,
+			i, id, total_secs, stats->getwork_calls,
+			stats->getwork_wait.tv_sec, stats->getwork_wait.tv_usec,
+			stats->getwork_wait_max.tv_sec, stats->getwork_wait_max.tv_usec,
+			stats->getwork_wait_min.tv_sec, stats->getwork_wait_min.tv_usec);
+
+		strcat(io_buffer, buf);
+
+		i++;
+	}
+
+	return i;
+}
+static void minerstats(__maybe_unused SOCKETTYPE c, __maybe_unused char *param, bool isjson)
+{
+	char buf[BUFSIZ];
+	int i, j;
+
+	strcpy(io_buffer, message(MSG_MINESTATS, 0, NULL, isjson));
+
+	if (isjson) {
+		strcat(io_buffer, COMMA);
+		strcat(io_buffer, JSON_MINESTATS);
+	}
+
+	i = 0;
+	for (j = 0; j < total_devices; j++) {
+		struct cgpu_info *cgpu = devices[j];
+
+		if (cgpu && cgpu->api) {
+			sprintf(buf, "%s%d", cgpu->api->name, cgpu->device_id);
+			i = itemstats(i, buf, &(cgpu->cgminer_stats), isjson);
+		}
+	}
+
+	for (j = 0; j < total_pools; j++) {
+		struct pool *pool = pools[j];
+
+		sprintf(buf, "POOL%d", j);
+		i = itemstats(i, buf, &(pool->cgminer_stats), isjson);
+	}
+
+	if (isjson)
+		strcat(io_buffer, JSON_CLOSE);
+}
+
 struct CMDS {
 	char *name;
 	void (*func)(SOCKETTYPE, char *, bool);
@@ -2015,6 +2074,7 @@ struct CMDS {
 	{ "notify",		notify,		false },
 	{ "devdetails",		devdetails,	false },
 	{ "restart",		dorestart,	true },
+	{ "stats",		minerstats,	false },
 	{ NULL,			NULL,		false }
 };
 

miner.c

@@ -3743,6 +3743,9 @@ void *miner_thread(void *userdata)
 	const int thr_id = mythr->id;
 	struct cgpu_info *cgpu = mythr->cgpu;
 	const struct device_api *api = cgpu->api;
+	struct cgminer_stats *dev_stats = &(cgpu->cgminer_stats);
+	struct cgminer_stats *pool_stats;
+	struct timeval getwork_start;
 
 	/* Try to cycle approximately 5 times before each log update */
 	const unsigned long def_cycle = opt_log_interval / 5 ? : 1;
@@ -3758,6 +3761,8 @@ void *miner_thread(void *userdata)
 	bool requested = false;
 	pthread_setcanceltype(PTHREAD_CANCEL_ASYNCHRONOUS, NULL);
 
+	gettimeofday(&getwork_start, NULL);
+
 	if (api->thread_init && !api->thread_init(mythr)) {
 		cgpu->device_last_not_well = time(NULL);
 		cgpu->device_not_well_reason = REASON_THREAD_FAIL_INIT;
@@ -3796,7 +3801,40 @@ void *miner_thread(void *userdata)
 		do {
 			gettimeofday(&tv_start, NULL);
 
+			timersub(&tv_start, &getwork_start, &getwork_start);
+
+			timeradd(&getwork_start,
+				&(dev_stats->getwork_wait),
+				&(dev_stats->getwork_wait));
+			if (timercmp(&getwork_start, &(dev_stats->getwork_wait_max), >)) {
+				dev_stats->getwork_wait_max.tv_sec = getwork_start.tv_sec;
+				dev_stats->getwork_wait_max.tv_usec = getwork_start.tv_usec;
+			}
+			if (timercmp(&getwork_start, &(dev_stats->getwork_wait_min), <)) {
+				dev_stats->getwork_wait_min.tv_sec = getwork_start.tv_sec;
+				dev_stats->getwork_wait_min.tv_usec = getwork_start.tv_usec;
+			}
+			dev_stats->getwork_calls++;
+
+			pool_stats = &(work->pool->cgminer_stats);
+
+			timeradd(&getwork_start,
+				&(pool_stats->getwork_wait),
+				&(pool_stats->getwork_wait));
+			if (timercmp(&getwork_start, &(pool_stats->getwork_wait_max), >)) {
+				pool_stats->getwork_wait_max.tv_sec = getwork_start.tv_sec;
+				pool_stats->getwork_wait_max.tv_usec = getwork_start.tv_usec;
+			}
+			if (timercmp(&getwork_start, &(pool_stats->getwork_wait_min), <)) {
+				pool_stats->getwork_wait_min.tv_sec = getwork_start.tv_sec;
+				pool_stats->getwork_wait_min.tv_usec = getwork_start.tv_usec;
+			}
+			pool_stats->getwork_calls++;
+
 			hashes = api->scanhash(mythr, work, work->blk.nonce + max_nonce);
+
+			gettimeofday(&getwork_start, NULL);
+
 			if (unlikely(work_restart[thr_id].restart)) {
 
 				/* Apart from device_thread 0, we stagger the
@@ -4964,6 +5002,9 @@ int main(int argc, char *argv[])
 
 	load_temp_cutoffs();
 
+	for (i = 0; i < total_devices; ++i)
+		devices[i]->cgminer_stats.getwork_wait_min.tv_sec = MIN_SEC_UNSET;
+
 	logstart += total_devices;
 	logcursor = logstart + 1;
 
@@ -4982,6 +5023,8 @@ int main(int argc, char *argv[])
 	for (i = 0; i < total_pools; i++) {
 		struct pool *pool = pools[i];
 
+		pool->cgminer_stats.getwork_wait_min.tv_sec = MIN_SEC_UNSET;
+
 		if (!pool->rpc_userpass) {
 			if (!pool->rpc_user || !pool->rpc_pass)
 				quit(1, "No login credentials supplied for pool %u %s", i, pool->rpc_url);

miner.h

@@ -252,6 +252,15 @@ enum dev_reason {
 #define REASON_DEV_THERMAL_CUTOFF_STR	"Device reached thermal cutoff"
 #define REASON_UNKNOWN_STR		"Unknown reason - code bug"
 
+#define MIN_SEC_UNSET 99999999
+
+struct cgminer_stats {
+	uint32_t getwork_calls;
+	struct timeval getwork_wait;
+	struct timeval getwork_wait_max;
+	struct timeval getwork_wait_min;
+};
+
 struct cgpu_info {
 	int cgminer_id;
 	const struct device_api *api;
@@ -324,6 +333,8 @@ struct cgpu_info {
 	int dev_nostart_count;
 	int dev_over_heat_count;	// It's a warning but worth knowing
 	int dev_thermal_cutoff_count;
+
+	struct cgminer_stats cgminer_stats;
 };
 
 extern bool add_cgpu(struct cgpu_info*);
@@ -653,6 +664,8 @@ struct pool {
 	struct list_head curlring;
 
 	time_t last_share_time;
+
+	struct cgminer_stats cgminer_stats;
 };
 
 struct work {