Unmap when VCL goes cold, re-map on the warm event.

The PRIV_VCL list is now a list of reader objects. On the warm event,
we restart the timer and then wait for the first check to run, as
in object init.

src/tests/temperature.vtc

@@ -25,47 +25,95 @@ varnish v1 -arg "-p debug=+vclrel" -vcl {
 } -start
 
 logexpect l1 -v v1 -d 1 -g raw -q "Debug" {
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
 
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
 
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
 
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
 
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
 } -run
 
 varnish v1 -vcl { backend b None; }
 
+logexpect l1 -v v1 -d 0 -g raw -q "Debug" {
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: timer suspended$}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: unmapped$}
+
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: timer suspended$}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: unmapped$}
+
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: timer suspended$}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: unmapped$}
+
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: timer suspended$}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: unmapped$}
+
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: timer suspended$}
+	expect 0 0 Debug	{^vmod file: vcl1\.rdr\d: unmapped$}
+} -start
+
 varnish v1 -cliok "vcl.state vcl1 cold"
+
+logexpect l1 -wait
+
 varnish v1 -cliok "vcl.list"
 
 delay .5
 # No checks run in the cold state, must be verified manually in the log.
 
 logexpect l1 -v v1 -d 0 -g raw -q "Debug" {
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: timer restarted$}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: re-mapped$}
+
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: timer restarted$}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: re-mapped$}
+
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: timer restarted$}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: re-mapped$}
+
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: timer restarted$}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: re-mapped$}
+
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: timer restarted$}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: re-mapped$}
+} -start
+
+logexpect l2 -v v1 -d 0 -g raw -q "Debug" {
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
 
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
 
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
 
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
 
-	expect * * Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ running at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: updating \S+ at}
+	expect * 0 Debug	{^vmod file: vcl1\.rdr\d: check for \S+ finished successfully at}
 } -start
 
 varnish v1 -cliok "vcl.state vcl1 warm"
 
 logexpect l1 -wait
+logexpect l2 -wait

src/vmod_file.c

@@ -85,6 +85,7 @@ struct file_info {
 #define RDR_MAPPED	(1 << 2)
 #define RDR_TIMER_INIT	(1 << 3)
 #define RDR_DELETED	(1 << 4)
+#define RDR_WARMUP	(1 << 5)
 
 struct VPFX(file_reader) {
 	unsigned		magic;
@@ -100,14 +101,14 @@ struct VPFX(file_reader) {
 	unsigned short		errlen;
 };
 
-struct timer_entry {
-	unsigned		magic;
-#define TIMER_ENTRY_MAGIC 0xa0059ebd
-	VSLIST_ENTRY(timer_entry) list;
-	timer_t			timerid;
+struct obj_entry {
+	unsigned			magic;
+#define OBJ_ENTRY_MAGIC 0xace45740
+	VSLIST_ENTRY(obj_entry) 	list;
+	struct VPFX(file_reader)	*obj;
 };
 
-VSLIST_HEAD(timer_head, timer_entry);
+VSLIST_HEAD(obj_head, obj_entry);
 
 static void
 check(union sigval val)
@@ -185,7 +186,7 @@ check(union sigval val)
 		goto out;
 	}
 
-	if ((flags & (RDR_INITIALIZED | RDR_MAPPED))
+	if ((flags & (RDR_INITIALIZED | RDR_MAPPED) & !(flags & RDR_WARMUP))
 	    && info->mtime.tv_sec == st.st_mtim.tv_sec
 	    && info->mtime.tv_nsec == st.st_mtim.tv_nsec
 	    && info->dev == st.st_dev && info->ino == st.st_ino) {
@@ -248,7 +249,7 @@ check(union sigval val)
 	info->ino = st.st_ino;
 	info->len = st.st_size + 1;
 
-	flags &= ~RDR_ERROR;
+	flags &= ~(RDR_ERROR | RDR_WARMUP);
 	flags |= RDR_INITIALIZED;
 
  out:
@@ -296,21 +297,21 @@ check(union sigval val)
 	return;
 }
 
-static struct timer_head *
+static struct obj_head *
 init_priv_vcl(struct vmod_priv *priv)
 {
-	struct timer_head *th;
+	struct obj_head *objh;
 
 	AN(priv);
 	if (priv->priv == NULL) {
-		th = malloc(sizeof(*th));
-		AN(th);
-		priv->priv = th;
-		VSLIST_INIT(th);
+		objh = malloc(sizeof(*objh));
+		AN(objh);
+		priv->priv = objh;
+		VSLIST_INIT(objh);
 	}
 	else
-		th = priv->priv;
-	return (th);
+		objh = priv->priv;
+	return (objh);
 }
 
 VCL_VOID
@@ -324,8 +325,8 @@ vmod_reader__init(VRT_CTX, struct VPFX(file_reader) **rdrp,
 	struct sigevent sigev;
 	timer_t timerid;
 	struct itimerspec timerspec;
-	struct timer_head *th;
-	struct timer_entry *tent;
+	struct obj_head *objh;
+	struct obj_entry *objent;
 
 	CHECK_OBJ_NOTNULL(ctx, VRT_CTX_MAGIC);
 	AN(rdrp);
@@ -469,17 +470,17 @@ vmod_reader__init(VRT_CTX, struct VPFX(file_reader) **rdrp,
 	timerspec.it_interval.tv_nsec
 		= (long)(1e9 * (ttl - timerspec.it_interval.tv_sec));
 
-	th = init_priv_vcl(priv);
-	AN(th);
+	objh = init_priv_vcl(priv);
+	AN(objh);
 	errno = 0;
-	ALLOC_OBJ(tent, TIMER_ENTRY_MAGIC);
-	if (tent == NULL) {
-		VFAIL(ctx, "new %s: allocating timer list entry: %s", vcl_name,
+	ALLOC_OBJ(objent, OBJ_ENTRY_MAGIC);
+	if (objent == NULL) {
+		VFAIL(ctx, "new %s: allocating object list entry: %s", vcl_name,
 		      vstrerror(errno));
 		return;
 	}
-	tent->timerid = timerid;
-	VSLIST_INSERT_HEAD(th, tent, list);
+	objent->obj = rdr;
+	VSLIST_INSERT_HEAD(objh, objent, list);
 
 	AZ(rdr->addr);
 	AZ(rdr->info->mtime.tv_sec);
@@ -534,6 +535,7 @@ vmod_reader__fini(struct VPFX(file_reader) **rdrp)
 		CHECK_OBJ_NOTNULL(rdr->info, FILE_INFO_MAGIC);
 		AN(rdr->addr);
 		AN(rdr->obj_name);
+		AN(rdr->vcl_name);
 
 		errno = 0;
 		if (munmap(rdr->addr, rdr->info->len) != 0)
@@ -806,33 +808,48 @@ vmod_version(VRT_CTX)
 int
 VPFX(event)(VRT_CTX, struct vmod_priv *priv, enum vcl_event_e e)
 {
-	struct timer_head *th;
-	struct timer_entry *ent;
+	struct obj_head *objh;
+	struct obj_entry *ent;
 	struct itimerspec timer;
+	struct VPFX(file_reader) *rdr;
+	int flags;
 
 	ASSERT_CLI();
 	CHECK_OBJ_NOTNULL(ctx, VRT_CTX_MAGIC);
 	AN(priv);
 
-	th = init_priv_vcl(priv);
-	AN(th);
+	objh = init_priv_vcl(priv);
+	AN(objh);
 
 	switch (e) {
 	case VCL_EVENT_DISCARD:
-		while (!VSLIST_EMPTY(th)) {
-			/* object .fini deletes the timers */
-			ent = VSLIST_FIRST(th);
-			CHECK_OBJ_NOTNULL(ent, TIMER_ENTRY_MAGIC);
-			VSLIST_REMOVE_HEAD(th, list);
+		/* just free the list, object .fini unmaps and deletes timers */
+		while (!VSLIST_EMPTY(objh)) {
+			ent = VSLIST_FIRST(objh);
+			CHECK_OBJ_NOTNULL(ent, OBJ_ENTRY_MAGIC);
+			VSLIST_REMOVE_HEAD(objh, list);
 			FREE_OBJ(ent);
 		}
-		free(th);
+		free(objh);
 		return (0);
 	case VCL_EVENT_WARM:
-		VSLIST_FOREACH(ent, th, list) {
-			CHECK_OBJ_NOTNULL(ent, TIMER_ENTRY_MAGIC);
+		VSLIST_FOREACH(ent, objh, list) {
+			CHECK_OBJ_NOTNULL(ent, OBJ_ENTRY_MAGIC);
+			CHECK_OBJ_NOTNULL(ent->obj, FILE_READER_MAGIC);
+			rdr = ent->obj;
+			AN(rdr->lock);
+			AN(rdr->vcl_name);
+			AN(rdr->obj_name);
+			AN(rdr->errbuf);
+
+			if (rdr->flags & RDR_TIMER_INIT)
+				continue;
+
+			rdr->flags |= RDR_WARMUP;
+			rdr->flags &= ~(RDR_ERROR | RDR_DELETED);
+
 			errno = 0;
-			if (timer_gettime(ent->timerid, &timer) != 0) {
+			if (timer_gettime(rdr->timerid, &timer) != 0) {
 				VSB_printf(ctx->msg,
 					   "vmod file: reading timer: %s",
 					   vstrerror(errno));
@@ -840,32 +857,88 @@ VPFX(event)(VRT_CTX, struct vmod_priv *priv, enum vcl_event_e e)
 			}
 			timer.it_value.tv_sec = 0;
 			timer.it_value.tv_nsec = 1;
-			if (timer_settime(ent->timerid, 0, &timer, NULL) != 0) {
+			if (timer_settime(rdr->timerid, 0, &timer, NULL) != 0) {
 				VSB_printf(ctx->msg,
 					   "vmod file: restarting timer: %s",
 					   vstrerror(errno));
 				return (-1);
 			}
+			VSL(SLT_Debug, 0, "vmod file: %s.%s: timer restarted",
+			    rdr->vcl_name, rdr->obj_name);
+
+			if (rdr->flags & RDR_MAPPED)
+				continue;
+
+			/* wait for the initial update, as in object init */
+			do {
+				VTIM_sleep(INIT_SLEEP_INTERVAL);
+				AZ(pthread_rwlock_rdlock(rdr->lock));
+				flags = rdr->flags;
+				AZ(pthread_rwlock_unlock(rdr->lock));
+			} while (flags & RDR_WARMUP);
+
+			if (rdr->flags & RDR_ERROR) {
+				AN(strcmp(rdr->errbuf, NO_ERR));
+				VSB_printf(ctx->msg, "vmod file: %s.%s: %s",
+					   rdr->vcl_name, rdr->obj_name,
+					   rdr->errbuf);
+				return (-1);
+			}
+
+			AN(rdr->flags & RDR_MAPPED);
+			AZ(rdr->flags & RDR_DELETED);
+			AN(rdr->addr);
+			VSL(SLT_Debug, 0, "vmod file: %s.%s: re-mapped",
+			    rdr->vcl_name, rdr->obj_name);
 		}
 		return (0);
 	case VCL_EVENT_COLD:
-		VSLIST_FOREACH(ent, th, list) {
-			CHECK_OBJ_NOTNULL(ent, TIMER_ENTRY_MAGIC);
+		VSLIST_FOREACH(ent, objh, list) {
+			CHECK_OBJ_NOTNULL(ent, OBJ_ENTRY_MAGIC);
+			CHECK_OBJ_NOTNULL(ent->obj, FILE_READER_MAGIC);
+			rdr = ent->obj;
+			AN(rdr->vcl_name);
+			AN(rdr->obj_name);
+			AN(rdr->errbuf);
+
 			errno = 0;
-			if (timer_gettime(ent->timerid, &timer) != 0) {
+			if (timer_gettime(rdr->timerid, &timer) != 0) {
 				VSL(SLT_Error, 0,
-				    "vmod file: reading timer: %s",
+				    "vmod file: %s.%s: reading timer: %s",
+				    rdr->vcl_name, rdr->obj_name,
 				    vstrerror(errno));
 				continue;
 			}
 			timer.it_value.tv_sec = 0;
 			timer.it_value.tv_nsec = 0;
-			if (timer_settime(ent->timerid, 0, &timer, NULL) != 0) {
-				VSL(SLT_Debug, 0,
-				    "vmod file: suspending timer: %s",
+			if (timer_settime(rdr->timerid, 0, &timer, NULL) != 0) {
+				VSL(SLT_Error, 0,
+				    "vmod file: %s.%s: suspending timer: %s",
+				    rdr->vcl_name, rdr->obj_name,
+				    vstrerror(errno));
+				continue;
+			}
+			rdr->flags &= ~RDR_TIMER_INIT;
+			VSL(SLT_Debug, 0, "vmod file: %s.%s: timer suspended",
+			    rdr->vcl_name, rdr->obj_name);
+
+			if ((rdr->flags & RDR_MAPPED) == 0)
+				continue;
+
+			CHECK_OBJ_NOTNULL(rdr->info, FILE_INFO_MAGIC);
+			AN(rdr->addr);
+			errno = 0;
+			if (munmap(rdr->addr, rdr->info->len) != 0) {
+				VSL(SLT_Error, 0,
+				    "vmod file: %s.%s: unmap failed: %s",
+				    rdr->vcl_name, rdr->obj_name,
 				    vstrerror(errno));
 				continue;
 			}
+			rdr->flags &= ~RDR_MAPPED;
+			rdr->addr = NULL;
+			VSL(SLT_Debug, 0, "vmod file: %s.%s: unmapped",
+			    rdr->vcl_name, rdr->obj_name);
 		}
 		return (0);
 	case VCL_EVENT_LOAD: