add some instrumentation to measure pipeline stage time.

3 files changed, 49 insertions, 2 deletions

diff --git a/camera.c b/camera.c
index 123db32..c0c897d 100644
--- a/camera.c
+++ b/camera.c
@@ -21,6 +21,16 @@ updatestats(Camera *c, uvlong v)
 }
 
 static void
+updatetimes(Camera *c, Renderjob *j)
+{
+	c->times.R[c->times.cur] = j->times.R;
+	c->times.E[c->times.cur] = j->times.E;
+	c->times.Tn[c->times.cur] = j->times.Tn;
+	c->times.Rn[c->times.cur] = j->times.Rn;
+	c->times.cur = ++c->times.cur % nelem(c->times.R);
+}
+
+static void
 verifycfg(Camera *c)
 {
 	assert(c->vp != nil);
@@ -98,6 +108,7 @@ shootcamera(Camera *c, Shadertab *s)
 	t1 = nanosec();
 	c->vp->fbctl->swap(c->vp->fbctl);
 
+	updatetimes(c, job);
 	chanfree(job->donec);
 	free(job);
 
diff --git a/graphics.h b/graphics.h
index 612ff48..1fc23c1 100644
--- a/graphics.h
+++ b/graphics.h
@@ -29,6 +29,7 @@ typedef struct FSparams FSparams;
 typedef struct SUparams SUparams;
 typedef struct Shadertab Shadertab;
 typedef struct Renderer Renderer;
+typedef struct Rendertime Rendertime;
 typedef struct Renderjob Renderjob;
 typedef struct Framebuf Framebuf;
 typedef struct Framebufctl Framebufctl;
@@ -175,6 +176,11 @@ struct Renderer
 	Channel *c;
 };
 
+struct Rendertime
+{
+	uvlong t0, t1;
+};
+
 struct Renderjob
 {
 	Ref;
@@ -183,6 +189,10 @@ struct Renderjob
 	Shadertab *shaders;
 	Channel *donec;
 
+	struct {
+		Rendertime R, E, Tn, Rn;
+	} times;
+
 	Renderjob *next;
 };
 
@@ -234,6 +244,11 @@ struct Camera
 		uvlong min, avg, max, acc, n, v;
 		uvlong nframes;
 	} stats;
+
+	struct {
+		Rendertime R[100], E[100], Tn[100], Rn[100];
+		int cur;
+	} times;
 };
 
 /* camera */
diff --git a/render.c b/render.c
index b1369a9..52dfbe7 100644
--- a/render.c
+++ b/render.c
@@ -361,6 +361,7 @@ rasterizer(void *arg)
 	Rastertask *task;
 	SUparams *params;
 	Memimage *frag;
+	uvlong t0;
 
 	threadsetname("rasterizer");
 
@@ -368,6 +369,8 @@ rasterizer(void *arg)
 	frag = rgb(DBlack);
 
 	while((task = recvp(taskc)) != nil){
+		t0 = nanosec();
+
 		params = task->params;
 		/* end of job */
 		if(params->entity == nil){
@@ -379,12 +382,16 @@ rasterizer(void *arg)
 			continue;
 		}
 
+		if(params->job->times.Rn.t0 == 0)
+			params->job->times.Rn.t0 = t0;
+
 		params->frag = frag;
 		rasterize(task);
 
 		delvattrs(&task->t[0]);
 		delvattrs(&task->t[1]);
 		delvattrs(&task->t[2]);
+		params->job->times.Rn.t1 = nanosec();
 		free(params);
 		free(task);
 	}
@@ -406,6 +413,7 @@ tilerdurden(void *arg)
 	Channel **taskc;
 	ulong Δx, nproc;
 	int i, nt;
+	uvlong t0;
 
 	threadsetname("tilerdurden");
 
@@ -416,6 +424,10 @@ tilerdurden(void *arg)
 	wr = emalloc(nproc*sizeof(Rectangle));
 
 	while((params = recvp(tp->paramsc)) != nil){
+		t0 = nanosec();
+		if(params->job->times.Tn.t0 == 0)
+			params->job->times.Tn.t0 = t0;
+
 		/* end of job */
 		if(params->entity == nil){
 			if(decref(params->job) < 1){
@@ -543,6 +555,7 @@ tilerdurden(void *arg)
 				delvattrs(&t[nt][2]);
 			}
 		}
+		params->job->times.Tn.t1 = nanosec();
 		free(params);
 	}
 }
@@ -557,6 +570,7 @@ entityproc(void *arg)
 	char *nprocs;
 	ulong stride, nelems, nproc, nworkers;
 	int i;
+	uvlong t0;
 
 	threadsetname("entityproc");
 
@@ -584,6 +598,10 @@ entityproc(void *arg)
 	}
 
 	while((params = recvp(paramsin)) != nil){
+		t0 = nanosec();
+		if(params->job->times.E.t0 == 0)
+			params->job->times.E.t0 = t0;
+
 		/* end of job */
 		if(params->entity == nil){
 			params->job->ref = nproc;
@@ -611,6 +629,7 @@ entityproc(void *arg)
 			newparams->ee = i == nworkers-1? ee: newparams->eb + stride;
 			sendp(paramsout[i], newparams);
 		}
+		params->job->times.E.t1 = nanosec();
 		free(params);
 	}
 }
@@ -634,9 +653,9 @@ renderer(void *arg)
 	proccreate(entityproc, paramsc, mainstacksize);
 
 	while((job = recvp(jobc)) != nil){
-		sc = job->scene;
 		time = nanosec();
-
+		job->times.R.t0 = time;
+		sc = job->scene;
 		if(sc->nents < 1){
 			nbsend(job->donec, nil);
 			continue;
@@ -658,6 +677,8 @@ renderer(void *arg)
 		memset(params, 0, sizeof *params);
 		params->job = job;
 		sendp(paramsc, params);
+
+		job->times.R.t1 = nanosec();
 	}
 }