Record the 'worker time' for each subproblem.

Along with the number of kernel launches, the controller will now also print the combined time spent on a subproblem from each worker. So if one worker spends 100 seconds and another worker spends 110 seconds on a subproblem, the worker time for that subproblem will be 210 seconds.

controller.cc

@@ -204,6 +204,7 @@ struct SubproblemProgress : Subproblem {
     ZZ solution;
 
     unsigned int kernel_launch_count;
+    unsigned long long worker_time_ms;
     unsigned int num_workers_replied;
     unsigned int worker_id_counter;
 
@@ -212,7 +213,7 @@ struct SubproblemProgress : Subproblem {
 	    // By default, 1 in 1000 points are distinguihed points.  The
 	    // number in the next line is 2^32/1000
 	    Subproblem(id, b, t, m, o, 4294967), solved(false), kernel_launch_count(0),
-		    num_workers_replied(0), worker_id_counter(0) {
+		    worker_time_ms(0), num_workers_replied(0), worker_id_counter(0) {
 
 	custom_desired_resources(order, desired_dpnodes, max_workers, dpfreq);
 
@@ -698,11 +699,13 @@ static void controller_worker_reader(struct bufferevent *bev, void *ctx)
 
     while(1) {
 	unsigned int kernel_launch_count = 0;
+	unsigned long long worker_time_ms = 0;
 
 	size_t len = evbuffer_get_length(input);
-	if (len < sizeof(kernel_launch_count)) return;
+	if (len < sizeof(kernel_launch_count)+sizeof(worker_time_ms)) return;
 
 	bufferevent_read(bev, &kernel_launch_count, sizeof(kernel_launch_count));
+	bufferevent_read(bev, &worker_time_ms, sizeof(worker_time_ms));
 
 	// this assumes that workers never leave a subproblem (never crash or get re-assigned)
 	// otherwise we'll miss out on the kernel_launch_count for some workers
@@ -710,14 +713,22 @@ static void controller_worker_reader(struct bufferevent *bev, void *ctx)
 	SubproblemProgress *spp = ctrlstate.workers.working[bev];
 
 	spp->kernel_launch_count += kernel_launch_count;
+	spp->worker_time_ms += worker_time_ms;
 	spp->num_workers_replied += 1;
 
 	if (spp->num_workers_replied == spp->workers.size()) {
-	    cout << "Timing (name, problemid, subproblemid, launches): "
+
+	    char worker_time_sec_buf[50];
+	    sprintf(worker_time_sec_buf, "%lld.%03lld",
+			spp->worker_time_ms / 1000,
+			spp->worker_time_ms % 1000);
+
+	    cout << "Timing (name, problemid, subproblemid, launches, worker_time): "
 	         << ctrlstate.worklist[0].first << ", "
 	         << ctrlstate.problemid << ", "
 	         << spp->problemid << ", "
-	         << spp->kernel_launch_count << "\n";
+	         << spp->kernel_launch_count << ", "
+	         << worker_time_sec_buf << "\n";
 	    cout.flush();
 
 	    spp->reset();

worker.cc

@@ -54,6 +54,7 @@ static struct WrkControllerState {
     WTState worker_thread_state;
     pthread_t worker_thread;
     unsigned int kernel_launch_count;
+    struct timeval time_started_calculations;
     unsigned int worker_id;
 
     WrkControllerState(): current_problem(NULL),
@@ -104,6 +105,8 @@ static void *worker_thread_start(void *data)
 
     bool filled_dp_buffer = false;
 
+    gettimeofday(&wrkctrlstate.time_started_calculations, NULL);
+
     {
 #ifdef DERANDOMIZE
 	RandomStreamPush push_seed;
@@ -222,6 +225,8 @@ static void controllerconn_reader(struct bufferevent *bev, void *ctx)
     WrkControllerConnInfo *info = (WrkControllerConnInfo *)ctx;
     unsigned char cmd[1];
     unsigned char subproblem[SUBPROBLEM_DESC_LEN];
+    struct timeval ended_working;
+    unsigned long long computation_length_ms;
 
     while(1) {
 	size_t len = evbuffer_get_length(input);
@@ -238,7 +243,15 @@ static void controllerconn_reader(struct bufferevent *bev, void *ctx)
 			break;
 		    case 'S':
 			stop_working();
+
+			gettimeofday(&ended_working, NULL);
+			computation_length_ms =
+			    (ended_working.tv_sec - wrkctrlstate.time_started_calculations.tv_sec) * 1000 +
+			    (ended_working.tv_usec - wrkctrlstate.time_started_calculations.tv_usec) / 1000;
+
 			bufferevent_write(bev, &(wrkctrlstate.kernel_launch_count), sizeof(wrkctrlstate.kernel_launch_count));
+			bufferevent_write(bev, &computation_length_ms, sizeof(computation_length_ms));
+
 			cout << "Launch count: " << wrkctrlstate.kernel_launch_count << "\n";
 			cout.flush();
 			break;