[PATCH 00/12] Standardize c/r error reporting (v3)

[PATCH 00/12] Standardize c/r error reporting (v3)

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Here is a completely new approach, basically verbatim implementing
Oren's recipe from last Friday.  It only implements the error part
to replace ckpt_write_err.  The intent would be for ckpt_debug to
also be replaced by ckpt_msg() which would be similar to ckpt_err()
except adding a prefix to the message.

My goal is for users to be able to get real errors printed to a logfile
for checkpoint and restart (not have to check dmesg) in ckpt-v19,
especially for things like 'oh you're on a btrfs which is not supported'.
Having to check dmesg seems to walk right into the 'toy implementation'
argument.

Thanks Oren for the detailed explanation of what you want to see, and
Matt for several excellent cleanup suggestions.

If there are no major objections then I'll add ckpt_err()s at restart
on top of this patchset, but probably hold off on converting ckpt_debugs
for a bit.  Note that the heavyweight semaphore means that for real
debugging we're only increasing the chances of hiding bugs with the
debugging, so I'm open to the idea of keeping ckpt_debug() as is.

You can fetch this tree as branch nov2.6 of
git://git.kernel.org/pub/scm/linux/kernel/git/sergeh/linux-cr.git
or see gitweb at http://git.kernel.org/gitweb.cgi?p=linux/kernel/git/sergeh/linux-cr.git;a=shortlog;h=refs/heads/nov2.6

thanks,
-serge

[PATCH 01/12] define a new set of functions for error and debug logging

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

The checkpoint context now includes buffers for an expanded
format and for messages to be written out.  A mutex protects
these buffers as they are being built up and written out.
ckpt_msg() will write general informative (debug) messages to
syslog and an optional user-provided logfile.  ckpt_err() will
write errors to the same places, and, if it is a checkpoint
operation, also to the checkpoint image.

(This is intended to implement Oren's suggestion verbatim)

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 checkpoint/sys.c                 |  175 ++++++++++++++++++++++++++++++++++++++
 include/linux/checkpoint.h       |   74 ++++++++++++++++
 include/linux/checkpoint_types.h |    5 +
 3 files changed, 254 insertions(+), 0 deletions(-)

diff --git a/checkpoint/sys.c b/checkpoint/sys.c
index 260a1ee..f50167a 100644
--- a/checkpoint/sys.c
+++ b/checkpoint/sys.c
@@ -248,6 +248,8 @@ static struct ckpt_ctx *ckpt_ctx_alloc(int fd, unsigned long uflags,
 	INIT_LIST_HEAD(&ctx->task_status);
 	spin_lock_init(&ctx->lock);
 #endif
+	
+	mutex_init(&ctx->msg_mutex);
 
 	err = -EBADF;
 	ctx->file = fget(fd);
@@ -339,6 +341,179 @@ int walk_task_subtree(struct task_struct *root,
 	return (ret < 0 ? ret : total);
 }
 
+void ckpt_msg_lock(struct ckpt_ctx *ctx)
+{
+	if (!ctx)
+		return;
+	mutex_lock(&ctx->msg_mutex);
+	ctx->msg[0] = '\0';
+	ctx->msglen = 1;
+}
+
+void ckpt_msg_unlock(struct ckpt_ctx *ctx)
+{
+	if (!ctx)
+		return;
+	mutex_unlock(&ctx->msg_mutex);
+}
+
+static inline int is_special_flag(char *s)
+{
+	if (*s == '%' && s[1] == '(' && s[2] != '\0' && s[3] == ')')
+		return 1;
+	return 0;
+}
+
+/*
+ * _ckpt_generate_fmt - handle the special flags in the enhanced format
+ * strings used by checkpoint/restart error messages.
+ * @ctx: checkpoint context
+ * @fmt: message format
+ *
+ * The special flags are surrounded by %() to help them visually stand
+ * out.  For instance, %(O) means an objref.  The following special
+ * flags are recognized:
+ *	E: error
+ *	O: objref
+ *	P: pointer
+ *	T: task
+ *	S: string
+ *	V: variable
+ *
+ * %(E) will be expanded to "[err %d]".  Likewise O, P, S, and V, will
+ * also expand to format flags requiring an argument to the subsequent
+ * sprintf or printk.  T will be expanded to a string with no flags,
+ * requiring no further arguments.
+ *
+ * These do not accept any extra flags (i.e. min field width, precision,
+ * etc).
+ *
+ * The caller of ckpt_write_err() and _ckpt_write_err() must provide
+ * the additional variabes, in order, to match the @fmt (except for
+ * the T key), e.g.:
+ *
+ *	ckpt_write_err(ctx, "%(T)FILE flags %d %O %E\n", flags, objref, err);
+ *
+ * Must be called with ctx->fmt_buf_lock held.  The expanded format
+ * will be placed in ctx->fmt_buf.
+ */
+void _ckpt_generate_fmt(struct ckpt_ctx *ctx, char *fmt)
+{
+	char *s = ctx->fmt;
+	int len = 0;
+	int first = 1;
+
+	for (; *fmt && len < CKPT_MSG_LEN; fmt++) {
+		if (!is_special_flag(fmt)) {
+			s[len++] = *fmt;
+			continue;
+		}
+		if (!first)
+			s[len++] = ' ';
+		else
+			first = 0;
+		switch (fmt[2]) {
+		case 'E':
+			len += snprintf(s+len, CKPT_MSG_LEN-len, "[err %%d]");
+			break;
+		case 'O':
+			len += snprintf(s+len, CKPT_MSG_LEN-len, "[obj %%d]");
+			break;
+		case 'P':
+			len += snprintf(s+len, CKPT_MSG_LEN-len, "[ptr %%p]");
+			break;
+		case 'V':
+			len += snprintf(s+len, CKPT_MSG_LEN-len, "[sym %%pS]");
+			break;
+		case 'S':
+			len += snprintf(s+len, CKPT_MSG_LEN-len, "[str %%s]");
+			break;
+		case 'T':
+			if (ctx->tsk)
+				len += snprintf(s+len, CKPT_MSG_LEN-len,
+					"[pid %d tsk %s]",
+					task_pid_vnr(ctx->tsk), ctx->tsk->comm);
+			else
+				len += snprintf(s+len, CKPT_MSG_LEN-len,
+					"[pid -1 tsk NULL]");
+			break;
+		default:
+			printk(KERN_ERR "c/r: bad format specifier %c\n",
+					fmt[2]);
+			BUG();
+		}
+		fmt += 3;
+	}
+}
+
+static void _ckpt_msg_appendv(struct ckpt_ctx *ctx, char *fmt, va_list ap)
+{
+	int len = ctx->msglen;
+
+	len += vsnprintf(&ctx->msg[len], CKPT_MSG_LEN-len, fmt, ap);
+	if (len > CKPT_MSG_LEN) {
+		len = CKPT_MSG_LEN;
+		ctx->msg[CKPT_MSG_LEN-1] = '\0';
+	}
+	ctx->msglen = len;
+}
+
+void _ckpt_msg_append(struct ckpt_ctx *ctx, char *fmt, ...)
+{
+	va_list ap;
+
+	va_start(ap, fmt);
+	_ckpt_msg_appendv(ctx, fmt, ap);
+	va_end(ap);
+}
+
+void _ckpt_msg_complete(struct ckpt_ctx *ctx)
+{
+	int ret;
+
+	if (ctx->kflags & CKPT_CTX_CHECKPOINT) {
+		ret = ckpt_write_obj_type(ctx, NULL, 0, CKPT_HDR_ERROR);
+		if (!ret)
+			ret = ckpt_write_string(ctx, ctx->msg, ctx->msglen);
+		if (ret < 0)
+			printk(KERN_NOTICE "c/r: error string unsaved (%d): %s\n",
+			       ret, ctx->msg+1);
+	}
+#if 0
+	if (ctx->logfile) {
+		mm_segment_t fs = get_fs();
+		set_fs(KERNEL_DS);
+		ret = _ckpt_kwrite(ctx->logfile, ctx->msg+1, ctx->msglen-1);
+		set_fs(fs);
+	}
+#endif
+#ifdef CONFIG_CHECKPOINT_DEBUG
+	printk(KERN_DEBUG "%s", ctx->msg+1);
+#endif
+}
+
+#define __do_ckpt_msg(ctx, fmt) do {		\
+	va_list ap;				\
+	_ckpt_generate_fmt(ctx, fmt);		\
+	va_start(ap, fmt);			\
+	_ckpt_msg_appendv(ctx, ctx->fmt, ap);	\
+	va_end(ap);				\
+} while (0)
+
+void _do_ckpt_msg(struct ckpt_ctx *ctx, char *fmt, ...)
+{
+	__do_ckpt_msg(ctx, fmt);
+}
+
+void do_ckpt_msg(struct ckpt_ctx *ctx, char *fmt, ...)
+{
+	if (!ctx) return;
+
+	ckpt_msg_lock(ctx);
+	__do_ckpt_msg(ctx, fmt);
+	_ckpt_msg_complete(ctx);
+	ckpt_msg_unlock(ctx);
+}
 
 /**
  * sys_checkpoint - checkpoint a container
diff --git a/include/linux/checkpoint.h b/include/linux/checkpoint.h
index dfcb59b..3083e06 100644
--- a/include/linux/checkpoint.h
+++ b/include/linux/checkpoint.h
@@ -74,6 +74,9 @@ extern int ckpt_write_string(struct ckpt_ctx *ctx, char *str, int len);
  * form: "[PREFMT]: @fmt", where PREFMT is constructed from @fmt0. See
  * checkpoint/checkpoint.c:__ckpt_generate_fmt() for details.
  */
+/*
+ * This is deprecated, replaced by ckpt_err() and ckpt_err_locked()
+ */
 extern void __ckpt_write_err(struct ckpt_ctx *ctx, char *fmt0, char *fmt, ...);
 extern int ckpt_write_err(struct ckpt_ctx *ctx, char *fmt0, char *fmt, ...);
 
@@ -342,6 +345,9 @@ static inline int ckpt_validate_errno(int errno)
 extern void restore_debug_free(struct ckpt_ctx *ctx);
 extern unsigned long ckpt_debug_level;
 
+/*
+ * This is deprecated
+ */
 /* use this to select a specific debug level */
 #define _ckpt_debug(level, fmt, args...)				\
 	do {								\
@@ -365,11 +371,79 @@ extern unsigned long ckpt_debug_level;
 
 static inline void restore_debug_free(struct ckpt_ctx *ctx) {}
 
+/*
+ * This is deprecated
+ */
 #define _ckpt_debug(level, fmt, args...)	do { } while (0)
 #define ckpt_debug(fmt, args...)		do { } while (0)
 
 #endif /* CONFIG_CHECKPOINT_DEBUG */
 
+/*
+ * prototypes for the new logging api
+ */
+
+extern void ckpt_msg_lock(struct ckpt_ctx *ctx);
+extern void ckpt_msg_unlock(struct ckpt_ctx *ctx);
+
+/*
+ * Expand fmt into ctx->fmt.
+ * This expands enhanced format flags such as %(T), which takes no
+ * arguments, and %(E), which will require a properly positioned
+ * int error argument.  Flags include:
+ *   T: Task
+ *   E: Errno
+ *   O: Objref
+ *   P: Pointer
+ *   S: string
+ *   V: Variable (symbol)
+ * May be called under spinlock.
+ * Must be called under ckpt_msg_lock.
+ */
+extern void _ckpt_generate_fmt(struct ckpt_ctx *ctx, char *fmt);
+/*
+ * Append formatted msg to ctx->msg[ctx->msg_len].
+ * Must be called after expanding format.
+ * May be called under spinlock.
+ * Must be called under ckpt_msg_lock().
+ */
+extern void _ckpt_msg_append(struct ckpt_ctx *ctx, char *fmt, ...);
+
+/*
+ * Write ctx->msg to all relevant places.
+ * Must not be called under spinlock.
+ * Must be called under ckpt_msg_lock().
+ */
+extern void _ckpt_msg_complete(struct ckpt_ctx *ctx);
+
+/*
+ * Append an enhanced formatted message to ctx->msg.
+ * This will not write the message out to the applicable files, so
+ * the caller will have to use _ckpt_msg_complete() to finish up.
+ * Must be called with ckpt_msg_lock held.
+ */
+extern void _do_ckpt_msg(struct ckpt_ctx *ctx, char *fmt, ...);
+
+/*
+ * Append an enhanced formatted message to ctx->msg.
+ * This will take the ckpt_msg_lock and also write the message out
+ * to the applicable files by calling _ckpt_msg_complete().
+ * Must not be called under spinlock.
+ */
+extern void do_ckpt_msg(struct ckpt_ctx *ctx, char *fmt, ...);
+
+#define ckpt_err(ctx, fmt, args...) do {					\
+	do_ckpt_msg(ctx, "[Error at %s:%d]" fmt, __func__, __LINE__,  ##args);	\
+} while (0)
+
+
+#define _ckpt_err(ctx, fmt, args...) do { \
+	_do_ckpt_msg(ctx, "[ error %s:%d]" fmt, __func__, __LINE__, ##args);	\
+} while (0)
+
+/* ckpt_logmsg() or ckpt_msg() will do do_ckpt_msg with an added
+ * prefix */
+
 #endif /* CONFIG_CHECKPOINT */
 #endif /* __KERNEL__ */
 
diff --git a/include/linux/checkpoint_types.h b/include/linux/checkpoint_types.h
index 5cc11d9..6771b9f 100644
--- a/include/linux/checkpoint_types.h
+++ b/include/linux/checkpoint_types.h
@@ -85,6 +85,11 @@ struct ckpt_ctx {
 	struct list_head task_status;   /* list of status for each task */
 	spinlock_t lock;
 #endif
+#define CKPT_MSG_LEN 1024
+	char fmt[CKPT_MSG_LEN];
+	char msg[CKPT_MSG_LEN];
+	int msglen;
+	struct mutex msg_mutex;
 };
 
 #endif /* __KERNEL__ */
-- 
1.6.1

[PATCH 02/12] switch ckpt_write_err callers to ckpt_err

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 arch/x86/mm/checkpoint.c |    4 ++--
 checkpoint/checkpoint.c  |   39 ++++++++++++++++++++++-----------------
 2 files changed, 24 insertions(+), 19 deletions(-)

diff --git a/arch/x86/mm/checkpoint.c b/arch/x86/mm/checkpoint.c
index 32d9dca..df5bf4b 100644
--- a/arch/x86/mm/checkpoint.c
+++ b/arch/x86/mm/checkpoint.c
@@ -154,11 +154,11 @@ static unsigned short decode_segment(__u16 seg)
 static int may_checkpoint_thread(struct ckpt_ctx *ctx, struct task_struct *t)
 {
 	if (t->thread.vm86_info) {
-		ckpt_write_err(ctx, "TE", "task in VM86 mode", -EBUSY);
+		ckpt_err(ctx, "%(T)%(E)Task in VM86 mode\n", -EBUSY);
 		return -EBUSY;
 	}
 	if (task_thread_info(t)->flags & CKPT_X86_TIF_UNSUPPORTED) {
-		ckpt_write_err(ctx, "TE", "bad thread info flags %#lx", -EBUSY);
+		ckpt_err(ctx, "%(T)%(E)Bad thread info flags %#lx\n", -EBUSY);
 		return -EBUSY;
 	}
 	return 0;
diff --git a/checkpoint/checkpoint.c b/checkpoint/checkpoint.c
index 6eb8f3b..30c6637 100644
--- a/checkpoint/checkpoint.c
+++ b/checkpoint/checkpoint.c
@@ -410,12 +410,12 @@ static int may_checkpoint_task(struct ckpt_ctx *ctx, struct task_struct *t)
 	ckpt_debug("check %d\n", task_pid_nr_ns(t, ctx->root_nsproxy->pid_ns));
 
 	if (t->exit_state == EXIT_DEAD) {
-		__ckpt_write_err(ctx, "TE", "task state EXIT_DEAD\n", -EBUSY);
+		_ckpt_err(ctx, "%(T)%(E)Task state EXIT_DEAD\n", -EBUSY);
 		return -EBUSY;
 	}
 
 	if (!ptrace_may_access(t, PTRACE_MODE_ATTACH)) {
-		__ckpt_write_err(ctx, "TE", "ptrace attach denied", -EPERM);
+		_ckpt_err(ctx, "%(T)%(E)Ptrace attach denied\n", -EPERM);
 		return -EPERM;
 	}
 
@@ -425,13 +425,13 @@ static int may_checkpoint_task(struct ckpt_ctx *ctx, struct task_struct *t)
 
 	/* verify that all tasks belongs to same freezer cgroup */
 	if (t != current && !in_same_cgroup_freezer(t, ctx->root_freezer)) {
-		__ckpt_write_err(ctx, "TE", "unfrozen or wrong cgroup", -EBUSY);
+		_ckpt_err(ctx, "%(T)%(E)Unfrozen or wrong cgroup\n", -EBUSY);
 		return -EBUSY;
 	}
 
 	/* FIX: add support for ptraced tasks */
 	if (task_ptrace(t)) {
-		__ckpt_write_err(ctx, "TE", "task is ptraced", -EBUSY);
+		_ckpt_err(ctx, "%(T)%(E)Task is ptraced\n", -EBUSY);
 		return -EBUSY;
 	}
 
@@ -441,22 +441,22 @@ static int may_checkpoint_task(struct ckpt_ctx *ctx, struct task_struct *t)
 	 */
 	if (ctx->root_init && t != root &&
 	    t->real_parent == root->real_parent && t->tgid != root->tgid) {
-		__ckpt_write_err(ctx, "TE", "task is sibling of root", -EINVAL);
+		_ckpt_err(ctx, "%(T)%(E)Task is sibling of root\n", -EINVAL);
 		return -EINVAL;
 	}
 
 	rcu_read_lock();
 	nsproxy = task_nsproxy(t);
 	if (nsproxy->mnt_ns != ctx->root_nsproxy->mnt_ns) {
-		__ckpt_write_err(ctx, "TE", "bad mnt_ns", -EPERM);
+		_ckpt_err(ctx, "%(T)%(E)Bad mnt_ns\n", -EPERM);
 		ret = -EPERM;
 	}
 	if (nsproxy->pid_ns != ctx->root_nsproxy->pid_ns) {
-		__ckpt_write_err(ctx, "TE", "bad pid_ns", -EPERM);
+		_ckpt_err(ctx, "%(T)%(E)Bad pid_ns\n", -EPERM);
 		ret = -EPERM;
 	}
 	if (nsproxy->net_ns != ctx->root_nsproxy->net_ns) {
-		__ckpt_write_err(ctx, "TE", "bad net_ns", -EPERM);
+		_ckpt_err(ctx, "%(T)%(E)Bad net_ns\n", -EPERM);
 		ret = -EPERM;
 	}
 	rcu_read_unlock();
@@ -526,7 +526,7 @@ static int collect_objects(struct ckpt_ctx *ctx)
 		ret = ckpt_collect_task(ctx, ctx->tasks_arr[n]);
 		if (ret < 0) {
 			ctx->tsk = ctx->tasks_arr[n];
-			ckpt_write_err(ctx, "TE", "collect failed", ret);
+			ckpt_err(ctx, "%(T)%(E)Collect failed\n", ret);
 			ctx->tsk = NULL;
 			break;
 		}
@@ -547,7 +547,7 @@ static int __tree_count_tasks(struct task_struct *task, void *data)
 	struct ckpt_ctx *ctx = d->ctx;
 	int ret;
 
-	ctx->tsk = task;  /* (for ckpt_write_err) */
+	ctx->tsk = task;  /* (for _ckpt_err()) */
 
 	/* is this task cool ? */
 	ret = may_checkpoint_task(ctx, task);
@@ -556,7 +556,8 @@ static int __tree_count_tasks(struct task_struct *task, void *data)
 
 	if (ctx->tasks_arr) {
 		if (d->nr == ctx->nr_tasks) {  /* unlikely... try again later */
-			__ckpt_write_err(ctx, "TE", "bad task count\n", -EBUSY);
+			_ckpt_err(ctx, "%(T)%(E)Bad task count (d->nr = %d)\n",
+				-EBUSY, d->nr);
 			ret = -EBUSY;
 			goto out;
 		}
@@ -566,8 +567,6 @@ static int __tree_count_tasks(struct task_struct *task, void *data)
 
 	ret = 1;
  out:
-	if (ret < 0)
-		ckpt_write_err(ctx, "", NULL);
 	ctx->tsk = NULL;
 	return ret;
 }
@@ -575,11 +574,17 @@ static int __tree_count_tasks(struct task_struct *task, void *data)
 static int tree_count_tasks(struct ckpt_ctx *ctx)
 {
 	struct ckpt_cnt_tasks data;
+	int ret;
 
 	data.ctx = ctx;
 	data.nr = 0;
 
-	return walk_task_subtree(ctx->root_task, __tree_count_tasks, &data);
+	ckpt_msg_lock(ctx);
+	ret = walk_task_subtree(ctx->root_task, __tree_count_tasks, &data);
+	ckpt_msg_unlock(ctx);
+	if (ret < 0)
+		_ckpt_msg_complete(ctx);
+	return ret;
 }
 
 /*
@@ -726,7 +731,7 @@ static int init_checkpoint_ctx(struct ckpt_ctx *ctx, pid_t pid)
 	ctx->root_init = is_container_init(task);
 
 	if (!(ctx->uflags & CHECKPOINT_SUBTREE) && !ctx->root_init) {
-		ckpt_write_err(ctx, "E", "not container init", -EINVAL);
+		ckpt_err(ctx, "%(E)Not container init\n", -EINVAL);
 		return -EINVAL;  /* cleanup by ckpt_ctx_free() */
 	}
 
@@ -753,7 +758,7 @@ long do_checkpoint(struct ckpt_ctx *ctx, pid_t pid)
 	if (ctx->root_freezer) {
 		ret = cgroup_freezer_begin_checkpoint(ctx->root_freezer);
 		if (ret < 0) {
-			ckpt_write_err(ctx, "E", "freezer cgroup failed", ret);
+			ckpt_err(ctx, "%(E)Freezer cgroup failed\n", ret);
 			return ret;
 		}
 	}
@@ -796,7 +801,7 @@ long do_checkpoint(struct ckpt_ctx *ctx, pid_t pid)
 
 	/* verify that all objects were indeed visited */
 	if (!ckpt_obj_visited(ctx)) {
-		ckpt_write_err(ctx, "E", "leak: unvisited", -EBUSY);
+		ckpt_err(ctx, "%(E)Leak: unvisited\n", -EBUSY);
 		ret = -EBUSY;
 		goto out;
 	}
-- 
1.6.1

[PATCH 03/12] checkpoint/files.c ckpt_write_err->ckpt_err

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 checkpoint/files.c |   16 ++++++++--------
 1 files changed, 8 insertions(+), 8 deletions(-)

diff --git a/checkpoint/files.c b/checkpoint/files.c
index 440b7a9..99aedda 100644
--- a/checkpoint/files.c
+++ b/checkpoint/files.c
@@ -88,7 +88,7 @@ int checkpoint_fname(struct ckpt_ctx *ctx, struct path *path, struct path *root)
 					  CKPT_HDR_FILE_NAME);
 	} else {
 		ret = PTR_ERR(fname);
-		ckpt_write_err(ctx, "TEP", "obtain filename (file)", ret);
+		ckpt_err(ctx, "%(T)%(E)%(P)Obtain filename (file)\n", ret);
 	}
 
 	kfree(buf);
@@ -204,20 +204,20 @@ int checkpoint_file(struct ckpt_ctx *ctx, void *ptr)
 	int ret;
 
 	if (!file->f_op || !file->f_op->checkpoint) {
-		ckpt_write_err(ctx, "TEPS", "f_op lacks checkpoint",
+		ckpt_err(ctx, "%(T)%(E)%(P)%(V)f_op lacks checkpoint\n",
 			       -EBADF, file, file->f_op);
 		ckpt_debug("f_op lacks checkpoint handler: %pS\n", file->f_op);
 		return -EBADF;
 	}
 	if (d_unlinked(file->f_dentry)) {
-		ckpt_write_err(ctx, "TEP", "unlinked file", -EBADF, file);
+		ckpt_err(ctx, "%(T)%(E)%(P)Unlinked file\n", -EBADF, file);
 		ckpt_debug("unlinked files are unsupported\n");
 		return -EBADF;
 	}
 
 	ret = file->f_op->checkpoint(ctx, file);
 	if (ret < 0)
-		ckpt_write_err(ctx, "TEP", "file checkpoint failed", ret, file);
+		ckpt_err(ctx, "%(T)%(E)%(P)file checkpoint failed\n", ret, file);
 	return ret;
 }
 
@@ -257,7 +257,7 @@ static int checkpoint_file_desc(struct ckpt_ctx *ctx,
 	ret = -EBADF;
 	if (!file) {
 		pr_warning("c/r: file descriptor gone?");
-		ckpt_write_err(ctx, "TEP", "file gone? (%d)", ret, file, fd);
+		ckpt_err(ctx, "%(T)%(E)%(P)File Gone? (%d)\n", ret, file, fd);
 		goto out;
 	}
 
@@ -360,7 +360,7 @@ int ckpt_collect_file(struct ckpt_ctx *ctx, struct file *file)
 	if (file->f_op->collect)
 		ret = file->f_op->collect(ctx, file);
 	if (ret < 0)
-		ckpt_write_err(ctx, "TEP", "file collect", ret, file);
+		ckpt_err(ctx, "%(T)%(E)%(P)File collect\n", ret, file);
 	return ret;
 }
 
@@ -379,7 +379,7 @@ static int collect_file_desc(struct ckpt_ctx *ctx,
 	rcu_read_unlock();
 
 	if (!file) {
-		ckpt_write_err(ctx, "TE", "file removed", -EBUSY, file);
+		ckpt_err(ctx, "%(T)%(E)%(P)File removed\n", -EBUSY, file);
 		return -EBUSY;
 	}
 
@@ -422,7 +422,7 @@ int ckpt_collect_file_table(struct ckpt_ctx *ctx, struct task_struct *t)
 
 	files = get_files_struct(t);
 	if (!files) {
-		ckpt_write_err(ctx, "TE", "files_struct missing", -EBUSY);
+		ckpt_err(ctx, "%(T)%(E)files_struct missing\n", -EBUSY);
 		return -EBUSY;
 	}
 	ret = collect_file_table(ctx, files);
-- 
1.6.1

[PATCH 04/12] checkpoint/memory.c ckpt_write_err->ckpt_err

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 checkpoint/memory.c |   10 +++++-----
 1 files changed, 5 insertions(+), 5 deletions(-)

diff --git a/checkpoint/memory.c b/checkpoint/memory.c
index 656614c..6cfd079 100644
--- a/checkpoint/memory.c
+++ b/checkpoint/memory.c
@@ -679,8 +679,8 @@ static int checkpoint_vmas(struct ckpt_ctx *ctx, struct mm_struct *mm)
 			 vma->vm_start, vma->vm_end, vma->vm_flags);
 
 		if (vma->vm_flags & CKPT_VMA_NOT_SUPPORTED) {
-			ckpt_write_err(ctx, "TE", "vma: bad flags (%#lx)\n",
-				       -ENOSYS, vma->vm_flags);
+			ckpt_err(ctx, "%(T)%(E)vma: bad flags (%#lx)\n",
+					-ENOSYS, vma->vm_flags);
 			ret = -ENOSYS;
 			break;
 		}
@@ -692,7 +692,7 @@ static int checkpoint_vmas(struct ckpt_ctx *ctx, struct mm_struct *mm)
 		else
 			ret = -ENOSYS;
 		if (ret < 0) {
-			ckpt_write_err(ctx, "TE", "vma: failed", ret);
+			ckpt_err(ctx, "%(T)%(E)vma: failed\n", ret);
 			break;
 		}
 		/*
@@ -821,7 +821,7 @@ static int collect_mm(struct ckpt_ctx *ctx, struct mm_struct *mm)
 	if (mm->exe_file) {
 		ret = ckpt_collect_file(ctx, mm->exe_file);
 		if (ret < 0) {
-			ckpt_write_err(ctx, "TE", "mm: collect exe_file", ret);
+			ckpt_err(ctx, "%(T)%(E)mm: collect exe_file\n", ret);
 			goto out;
 		}
 	}
@@ -831,7 +831,7 @@ static int collect_mm(struct ckpt_ctx *ctx, struct mm_struct *mm)
 			continue;
 		ret = ckpt_collect_file(ctx, file);
 		if (ret < 0) {
-			ckpt_write_err(ctx, "TE", "mm: collect vm_file", ret);
+			ckpt_err(ctx, "%(T)%(E)mm: collect vm_file\n", ret);
 			break;
 		}
 	}
-- 
1.6.1

[PATCH 05/12] checkpoint/objhash.c ckpt_write_err->ckpt_err

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 checkpoint/objhash.c |    8 ++++----
 1 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/checkpoint/objhash.c b/checkpoint/objhash.c
index 730dd82..5d72d04 100644
--- a/checkpoint/objhash.c
+++ b/checkpoint/objhash.c
@@ -657,7 +657,7 @@ static inline int obj_reverse_leak(struct ckpt_ctx *ctx, struct ckpt_obj *obj)
 	 * object while we were collecting, which we didn't catch.
 	 */
 	if (obj->ops->ref_users && !(ctx->uflags & CHECKPOINT_SUBTREE)) {
-		ckpt_write_err(ctx, "OP", "leak: reverse added late (%s)",
+		ckpt_err(ctx, "%(O)%(P)Leak: reverse added late (%s)\n",
 			       obj->objref, obj->ptr, obj->ops->obj_name);
 		return -EBUSY;
 	}
@@ -774,7 +774,7 @@ int ckpt_obj_visit(struct ckpt_ctx *ctx, void *ptr, enum obj_type type)
 	if (!obj) {
 		if (!(ctx->uflags & CHECKPOINT_SUBTREE)) {
 			/* if not found report reverse leak (full container) */
-			ckpt_write_err(ctx, "OP", "leak: reverse unknown (%s)",
+			ckpt_err(ctx, "%(O)%(P)Leak: reverse unknown (%s)\n",
 				       obj->objref, obj->ptr,
 				       obj->ops->obj_name);
 			return -EBUSY;
@@ -870,7 +870,7 @@ int ckpt_obj_contained(struct ckpt_ctx *ctx)
 
 		if (obj->ops->ref_users(obj->ptr) != obj->users) {
 			ckpt_debug("usage leak: %s\n", obj->ops->obj_name);
-			ckpt_write_err(ctx, "OP", "leak: usage (%d != %d (%s)",
+			ckpt_err(ctx, "%(O)%(P)Leak: usage (%d != %d (%s)\n",
 				       obj->objref, obj->ptr,
 				       obj->ops->ref_users(obj->ptr),
 				       obj->users, obj->ops->obj_name);
@@ -896,7 +896,7 @@ int ckpt_obj_visited(struct ckpt_ctx *ctx)
 		if (!(obj->flags & CKPT_OBJ_VISITED)) {
 			ckpt_debug("reverse leak: %s (%d)\n",
 				   obj->ops->obj_name, obj->objref);
-			ckpt_write_err(ctx, "OP", "leak: not visited (%s)",
+			ckpt_err(ctx, "%(O)%(P)Leak: not visited (%s)\n",
 				       obj->objref, obj->ptr,
 				       obj->ops->obj_name);
 			return 0;
-- 
1.6.1

[PATCH 06/12] checkpoint/process.c ckpt_write_err->ckpt_err

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 checkpoint/process.c |    8 ++++----
 1 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/checkpoint/process.c b/checkpoint/process.c
index 8e4a823..2c65e77 100644
--- a/checkpoint/process.c
+++ b/checkpoint/process.c
@@ -256,21 +256,21 @@ static int checkpoint_task_objs(struct ckpt_ctx *ctx, struct task_struct *t)
 	files_objref = checkpoint_obj_file_table(ctx, t);
 	ckpt_debug("files: objref %d\n", files_objref);
 	if (files_objref < 0) {
-		ckpt_write_err(ctx, "TE", "files_struct", files_objref);
+		ckpt_err(ctx, "%(T)%(E)files_struct\n", files_objref);
 		return files_objref;
 	}
 
 	mm_objref = checkpoint_obj_mm(ctx, t);
 	ckpt_debug("mm: objref %d\n", mm_objref);
 	if (mm_objref < 0) {
-		ckpt_write_err(ctx, "TE", "mm_struct", mm_objref);
+		ckpt_err(ctx, "%(T)%(E)mm_struct\n", mm_objref);
 		return mm_objref;
 	}
 
 	sighand_objref = checkpoint_obj_sighand(ctx, t);
 	ckpt_debug("sighand: objref %d\n", sighand_objref);
 	if (sighand_objref < 0) {
-		ckpt_write_err(ctx, "TE", "sighand_struct", sighand_objref);
+		ckpt_err(ctx, "%(T)%(E)sighand_struct\n", sighand_objref);
 		return sighand_objref;
 	}
 
@@ -303,7 +303,7 @@ static int checkpoint_task_objs(struct ckpt_ctx *ctx, struct task_struct *t)
 	if (first)
 		ret = checkpoint_obj_signal(ctx, t);
 	if (ret < 0)
-		ckpt_write_err(ctx, "TE", "signal_struct", ret);
+		ckpt_err(ctx, "%(T)%(E)signal_struct\n", ret);
 
 	return ret;
 }
-- 
1.6.1

[PATCH 07/12] checkpoint/signal.c ckpt_write_err->ckpt_err

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 checkpoint/signal.c |    8 ++++----
 1 files changed, 4 insertions(+), 4 deletions(-)

diff --git a/checkpoint/signal.c b/checkpoint/signal.c
index cdfb142..f34dbf4 100644
--- a/checkpoint/signal.c
+++ b/checkpoint/signal.c
@@ -287,7 +287,7 @@ static int checkpoint_sigpending(struct ckpt_ctx *ctx,
 	list_for_each_entry(q, &pending->list, list) {
 		/* TODO: remove after adding support for posix-timers */
 		if ((q->info.si_code & __SI_MASK) == __SI_TIMER) {
-			ckpt_write_err(ctx, "TE", "signal SI_TIMER", -ENOTSUPP);
+			ckpt_err(ctx, "%(T)%(E)signal SI_TIMER\n", -ENOTSUPP);
 			return -ENOTSUPP;
 		}
 		nr_pending++;
@@ -341,7 +341,7 @@ static int checkpoint_signal(struct ckpt_ctx *ctx, struct task_struct *t)
 
 	/* TODO: remove after adding support for posix-timers */
 	if (!list_empty(&signal->posix_timers)) {
-		ckpt_write_err(ctx, "TEP", "posix-timers\n", -ENOTSUPP, signal);
+		ckpt_err(ctx, "%(T)%(E)%(P)posix-timers\n", -ENOTSUPP, signal);
 		unlock_task_sighand(t, &flags);
 		ret = -ENOTSUPP;
 		goto out;
@@ -653,7 +653,7 @@ int checkpoint_task_signal(struct ckpt_ctx *ctx, struct task_struct *t)
 
 	/* temporarily borrow signal queue - see chekcpoint_sigpending() */
 	if (!lock_task_sighand(t, &flags)) {
-		ckpt_write_err(ctx, "TE", "signand missing", -EBUSY);
+		ckpt_err(ctx, "%(T)%(E)signand missing\n", -EBUSY);
 		return -EBUSY;
 	}
 	list_splice_init(&t->pending.list, &pending.list);
@@ -664,7 +664,7 @@ int checkpoint_task_signal(struct ckpt_ctx *ctx, struct task_struct *t)
 
 	/* re-attach the borrowed queue */
 	if (!lock_task_sighand(t, &flags)) {
-		ckpt_write_err(ctx, "TE", "signand missing", -EBUSY);
+		ckpt_err(ctx, "%(T)%(E)signand missing\n", -EBUSY);
 		return -EBUSY;
 	}
 	list_splice(&pending.list, &t->pending.list);
-- 
1.6.1

[PATCH 08/12] drivers/char/tty_io.c ckpt_write_err->ckpt_err

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 drivers/char/tty_io.c |   14 +++++++-------
 1 files changed, 7 insertions(+), 7 deletions(-)

diff --git a/drivers/char/tty_io.c b/drivers/char/tty_io.c
index 1b220c1..5a853a3 100644
--- a/drivers/char/tty_io.c
+++ b/drivers/char/tty_io.c
@@ -2622,19 +2622,19 @@ static int tty_can_checkpoint(struct ckpt_ctx *ctx, struct tty_struct *tty)
 {
 	/* only support pty driver */
 	if (tty->driver->type != TTY_DRIVER_TYPE_PTY) {
-		ckpt_write_err(ctx, "TSP", "tty: unknown driverv type %d",
+		ckpt_err(ctx, "%(T)%(S)%(P)tty: unknown driverv type %d\n",
 			       tty->driver, tty, tty->driver->type);
 		return 0;
 	}
 	/* only support unix98 style */
 	if (tty->driver->major != UNIX98_PTY_MASTER_MAJOR &&
 	    tty->driver->major != UNIX98_PTY_SLAVE_MAJOR) {
-		ckpt_write_err(ctx, "TP", "tty: legacy pty", tty);
+		ckpt_err(ctx, "%(T)%(P)tty: legacy pty\n", tty);
 		return 0;
 	}
 	/* only support n_tty ldisc */
 	if (tty->ldisc->ops->num != N_TTY) {
-		ckpt_write_err(ctx, "TSP", "tty: unknown ldisc type %d",
+		ckpt_err(ctx, "%(T)%(S)%(P)tty: unknown ldisc type %d\n",
 			       tty->ldisc->ops, tty, tty->ldisc->ops->num);
 		return 0;
 	}
@@ -2711,7 +2711,7 @@ static int tty_file_collect(struct ckpt_ctx *ctx, struct file *file)
 
 	if (tty->driver->subtype == PTY_TYPE_MASTER) {
 		if (!tty->link) {
-			ckpt_write_err(ctx, "TP", "tty: missing link\n", tty);
+			ckpt_err(ctx, "%(T)%(P)tty: missing link\n\n", tty);
 			return -EIO;
 		}
 		ckpt_debug("collecting slave tty: %p\n", tty->link);
@@ -2735,7 +2735,7 @@ static int checkpoint_tty_ldisc(struct ckpt_ctx *ctx, struct tty_struct *tty)
 	BUG_ON(tty->ldisc->ops->num != N_TTY);
 
 	if ((tty->flags & CKPT_LDISC_FLAGS) != CKPT_LDISC_GOOD) {
-		ckpt_write_err(ctx, "TP", "tty: bad ldisc flags %#lx\n",
+		ckpt_err(ctx, "%(T)%(P)tty: bad ldisc flags %#lx\n",
 			       tty, tty->flags);
 		return -EBUSY;
 	}
@@ -2808,7 +2808,7 @@ static int do_checkpoint_tty(struct ckpt_ctx *ctx, struct tty_struct *tty)
 	int ret;
 
 	if ((tty->flags & (CKPT_TTY_BAD | CKPT_TTY_GOOD)) != CKPT_TTY_GOOD) {
-		ckpt_write_err(ctx, "TP", "tty: bad flags %#lx\n",
+		ckpt_err(ctx, "%(T)%(P)tty: bad flags %#lx\n",
 			       tty, tty->flags);
 		return -EBUSY;
 	}
@@ -3035,7 +3035,7 @@ static struct tty_struct *do_restore_tty(struct ckpt_ctx *ctx)
 	if (master) {
 		file = pty_open_by_index("/dev/ptmx", h->index);
 		if (IS_ERR(file)) {
-			ckpt_write_err(ctx, "TE", "open ptmx", PTR_ERR(file));
+			ckpt_err(ctx, "%(T)%(E)Open ptmx\n", PTR_ERR(file));
 			tty = ERR_PTR(PTR_ERR(file));
 			goto out;
 		}
-- 
1.6.1

[PATCH 09/12] fs/eventpoll.c ckpt_write_err->ckpt_err

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 fs/eventpoll.c |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)

diff --git a/fs/eventpoll.c b/fs/eventpoll.c
index e07de97..3e177ef 100644
--- a/fs/eventpoll.c
+++ b/fs/eventpoll.c
@@ -1549,7 +1549,7 @@ unlock:
 	if (num_items != 0 || (num_items == 0 && rbp))
 		ret = -EBUSY; /* extra item(s) -- checkpoint obj leak */
 	if (ret)
-		ckpt_write_err(ctx, "E", " checkpointing epoll items.\n", ret);
+		ckpt_err(ctx, "%(E)Checkpointing epoll items.\n", ret);
 	return ret;
 }
 
-- 
1.6.1

[PATCH 10/12] net/{,unix}/checkpoint.c ckpt_write_err->ckpt_err

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 net/checkpoint.c      |   10 +++++-----
 net/unix/checkpoint.c |    5 +++--
 2 files changed, 8 insertions(+), 7 deletions(-)

diff --git a/net/checkpoint.c b/net/checkpoint.c
index dd23efd..19025cc 100644
--- a/net/checkpoint.c
+++ b/net/checkpoint.c
@@ -103,7 +103,7 @@ static int __sock_write_buffers(struct ckpt_ctx *ctx,
 		 *        future
 		 */
 		if (UNIXCB(skb).fp) {
-			ckpt_write_err(ctx, "TE", "af_unix: pass fd", -EBUSY);
+			ckpt_err(ctx, "%(T)%(E)af_unix: pass fd\n", -EBUSY);
 			return -EBUSY;
 		}
 
@@ -178,7 +178,7 @@ int sock_deferred_write_buffers(void *data)
 
 	dst_objref = ckpt_obj_lookup(ctx, dq->sk, CKPT_OBJ_SOCK);
 	if (dst_objref < 0) {
-		ckpt_write_err(ctx, "TE", "socket: owner gone?", dst_objref);
+		ckpt_err(ctx, "%(T)%(E)socket: owner gone?\n", dst_objref);
 		return dst_objref;
 	}
 
@@ -215,7 +215,7 @@ int ckpt_sock_getnames(struct ckpt_ctx *ctx, struct socket *sock,
 
 	ret = sock_getname(sock, loc, loc_len);
 	if (ret) {
-		ckpt_write_err(ctx, "TEP", "socket: getname local", ret, sock);
+		ckpt_err(ctx, "%(T)%(E)%(P)socket: getname local\n", ret, sock);
 		return -EINVAL;
 	}
 
@@ -223,7 +223,7 @@ int ckpt_sock_getnames(struct ckpt_ctx *ctx, struct socket *sock,
 	if (ret) {
 		if ((sock->sk->sk_type != SOCK_DGRAM) &&
 		    (sock->sk->sk_state == TCP_ESTABLISHED)) {
-			ckpt_write_err(ctx, "TEP", "socket: getname peer",
+			ckpt_err(ctx, "%(T)%(E)%(P)socket: getname peer\n",
 				       ret, sock);
 			return -EINVAL;
 		}
@@ -503,7 +503,7 @@ static int __do_sock_checkpoint(struct ckpt_ctx *ctx, struct sock *sk)
 	int ret;
 
 	if (!sock->ops->checkpoint) {
-		ckpt_write_err(ctx, "TEVP", "socket: proto_ops",
+		ckpt_err(ctx, "%(T)%(E)%(V)%(P)socket: proto_ops\n",
 			       -ENOSYS, sock->ops, sock);
 		return -ENOSYS;
 	}
diff --git a/net/unix/checkpoint.c b/net/unix/checkpoint.c
index 8b7cb22..055f0a5 100644
--- a/net/unix/checkpoint.c
+++ b/net/unix/checkpoint.c
@@ -126,8 +126,9 @@ int unix_checkpoint(struct ckpt_ctx *ctx, struct socket *sock)
 
 	if ((sock->sk->sk_state == TCP_LISTEN) &&
 	    !skb_queue_empty(&sock->sk->sk_receive_queue)) {
-		ckpt_write_err(ctx, "TEP", "af_unix: listen with pending peers",
-			       -EBUSY, sock);
+		ckpt_err(ctx,
+			 "%(T)%(E)%(P)af_unix: listen with pending peers\n",
+			 -EBUSY, sock);
 		return -EBUSY;
 	}
 
-- 
1.6.1

[PATCH 11/12] remove ckpt_write_err

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 checkpoint/checkpoint.c    |  178 --------------------------------------------
 include/linux/checkpoint.h |   11 ---
 2 files changed, 0 insertions(+), 189 deletions(-)

diff --git a/checkpoint/checkpoint.c b/checkpoint/checkpoint.c
index 30c6637..1c67950 100644
--- a/checkpoint/checkpoint.c
+++ b/checkpoint/checkpoint.c
@@ -96,184 +96,6 @@ int ckpt_write_string(struct ckpt_ctx *ctx, char *str, int len)
 	return ckpt_write_obj_type(ctx, str, len, CKPT_HDR_STRING);
 }
 
-/*
- * __ckpt_generate_fmt - generate standard checkpoint error message
- * @ctx: checkpoint context
- * @fmt0: c/r-format string
- * @fmt: message format
- *
- * This generates a unified format of checkpoint error messages, to
- * ease (after the failure) inspection by userspace tools. It converts
- * the (printf) message @fmt into a new format: "[PREFMT]: fmt".
- *
- * PREFMT is constructed from @fmt0 by subtituting format snippets
- * according to the contents of @fmt0.  The format characters in
- * @fmt0 can be E (error), O (objref), P (pointer), S (string) and
- * V (variable/symbol). For example, E will generate a "err %d" in
- * PREFMT (see prefmt_array below).
- *
- * If @fmt0 begins with T, PREFMT will begin with "pid %d tsk %s"
- * with the pid and the tsk->comm of the currently checkpointed task.
- * The latter is taken from ctx->tsk, and is it the responsbilility of
- * the caller to have a valid pointer there (in particular, functions
- * that iterate on the processes: collect_objects, checkpoint_task,
- * and tree_count_tasks).
- *
- * The caller of ckpt_write_err() and _ckpt_write_err() must provide
- * the additional variabes, in order, to match the @fmt0 (except for
- * the T key), e.g.:
- *
- *   ckpt_writ_err(ctx, "TEO", "FILE flags %d", err, objref, flags);
- *
- * Here, T is simply passed, E expects an integer (err), O expects an
- * integer (objref), and the last argument matches the format string.
- */
-static char *__ckpt_generate_fmt(struct ckpt_ctx *ctx, char *fmt0, char *fmt)
-{
-	static int warn_notask = 0;
-	static int warn_prefmt = 0;
-	char *format;
-	int i, j, len = 0;
-
-	static struct {
-		char key;
-		char *fmt;
-	} prefmt_array[] = {
-		{ 'E', "err %d" },
-		{ 'O', "obj %d" },
-		{ 'P', "ptr %p" },
-		{ 'V', "sym %pS" },
-		{ 'S', "str %s" },
-		{ 0, "??? %pS" },
-	};
-
-	/*
-	 * 17 for "pid %d" (plus space)
-	 * 21 for "tsk %s" (tsk->comm)
-	 * up to 8 per varfmt entry
-	 */
-	format = kzalloc(37 + 8 * strlen(fmt0) + strlen(fmt), GFP_KERNEL);
-	if (!format)
-		return NULL;
-
-	format[len++] = '[';
-
-	if (fmt0[0] == 'T') {
-		if (ctx->tsk)
-			len = sprintf(format, "pid %d tsk %s ",
-				      task_pid_vnr(ctx->tsk), ctx->tsk->comm);
-		else if (warn_notask++ < 5)
-			printk(KERN_ERR "c/r: no target task set\n");
-		fmt0++;
-	}
-
-	for (i = 0; i < strlen(fmt0); i++) {
-		for (j = 0; prefmt_array[j].key; j++)
-			if (prefmt_array[j].key == fmt0[i])
-				break;
-		if (!prefmt_array[j].key && warn_prefmt++ < 5)
-			printk(KERN_ERR "c/r: unknown prefmt %c\n", fmt0[i]);
-		len += sprintf(&format[len], "%s ", prefmt_array[j].fmt);
-	}
-
-	if (len > 1)
-		sprintf(&format[len-1], "]: %s", fmt);  /* erase last space */
-	else
-		sprintf(format, "%s", fmt);
-
-	return format;
-}
-
-/* see _ckpt_generate_fmt for information on @fmt0 */
-static void __ckpt_generate_err(struct ckpt_ctx *ctx, char *fmt0,
-				char *fmt, va_list ap)
-{
-	va_list aq;
-	char *format;
-	char *str;
-	int len;
-
-	format = __ckpt_generate_fmt(ctx, fmt0, fmt);
-	va_copy(aq, ap);
-
-	/*
-	 * prefix the error string with a '\0' to facilitate easy
-	 * backtrace to the beginning of the error message without
-	 * needing to parse the entire checkpoint image.
-	 */
-	ctx->err_string[0] = '\0';
-	str = &ctx->err_string[1];
-	len = vsnprintf(str, 255, format ? : fmt, ap) + 2;
-
-	if (len > 256) {
-		printk(KERN_NOTICE "c/r: error string truncated: ");
-		vprintk(fmt, aq);
-	}
-
-	va_end(aq);
-	kfree(format);
-
-	ckpt_debug("c/r: checkpoint error: %s\n", str);
-}
-
-/**
- * __ckpt_write_err - save an error string on the ctx->err_string
- * @ctx: checkpoint context
- * @fmt0: error pre-format
- * @fmt: message format
- * @...: arguments
- *
- * See _ckpt_generate_fmt for information on @fmt0.
- * Use this during checkpoint to report while holding a spinlock
- */
-void __ckpt_write_err(struct ckpt_ctx *ctx, char *fmt0, char *fmt, ...)
-{
-	va_list ap;
-
-	va_start(ap, fmt);
-	__ckpt_generate_err(ctx, fmt0, fmt, ap);
-	va_end(ap);
-}
-
-/**
- * ckpt_write_err - write an object describing an error
- * @ctx: checkpoint context
- * @pre: string pre-format
- * @fmt: error string format
- * @...: error string arguments
- *
- * See _ckpt_generate_fmt for information on @fmt0.
- * If @fmt is null, the string in the ctx->err_string will be used (and freed)
- */
-int ckpt_write_err(struct ckpt_ctx *ctx, char *fmt0, char *fmt, ...)
-{
-	va_list ap;
-	char *str;
-	int len, ret = 0;
-
-	if (fmt) {
-		va_start(ap, fmt);
-		__ckpt_generate_err(ctx, fmt0, fmt, ap);
-		va_end(ap);
-	}
-
-	str = ctx->err_string;
-	len = strlen(str + 1);
-	if (len == 0)	/* empty error string */
-		return 0;
-
-	len += 2; 	/* leading and trailing '\0' */
-	ret = ckpt_write_obj_type(ctx, NULL, 0, CKPT_HDR_ERROR);
-	if (!ret)
-		ret = ckpt_write_string(ctx, str, len);
-	if (ret < 0)
-		printk(KERN_NOTICE "c/r: error string unsaved (%d): %s\n",
-		       ret, str + 1);
-
-	str[1] = '\0';
-	return ret;
-}
-
 /***********************************************************************
  * Checkpoint
  */
diff --git a/include/linux/checkpoint.h b/include/linux/checkpoint.h
index 3083e06..6941da0 100644
--- a/include/linux/checkpoint.h
+++ b/include/linux/checkpoint.h
@@ -69,17 +69,6 @@ extern int ckpt_write_obj_type(struct ckpt_ctx *ctx,
 extern int ckpt_write_buffer(struct ckpt_ctx *ctx, void *ptr, int len);
 extern int ckpt_write_string(struct ckpt_ctx *ctx, char *str, int len);
 
-/*
- * Generate a checkpoint error message with unified format, of the
- * form: "[PREFMT]: @fmt", where PREFMT is constructed from @fmt0. See
- * checkpoint/checkpoint.c:__ckpt_generate_fmt() for details.
- */
-/*
- * This is deprecated, replaced by ckpt_err() and ckpt_err_locked()
- */
-extern void __ckpt_write_err(struct ckpt_ctx *ctx, char *fmt0, char *fmt, ...);
-extern int ckpt_write_err(struct ckpt_ctx *ctx, char *fmt0, char *fmt, ...);
-
 extern int _ckpt_read_obj_type(struct ckpt_ctx *ctx,
 			       void *ptr, int len, int type);
 extern int _ckpt_read_buffer(struct ckpt_ctx *ctx, void *ptr, int len);
-- 
1.6.1

[PATCH 12/12] add logfd to c/r api

[serue-r/Jw6+rmf7HQT0dZR+AlfA]

From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

and write msgs to user-provided logfile if one exists.

Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
---
 checkpoint/objhash.c             |    2 ++
 checkpoint/sys.c                 |   25 ++++++++++++++++++-------
 include/linux/checkpoint_types.h |    1 +
 include/linux/syscalls.h         |    5 +++--
 4 files changed, 24 insertions(+), 9 deletions(-)

diff --git a/checkpoint/objhash.c b/checkpoint/objhash.c
index 5d72d04..92c07d2 100644
--- a/checkpoint/objhash.c
+++ b/checkpoint/objhash.c
@@ -858,6 +858,8 @@ int ckpt_obj_contained(struct ckpt_ctx *ctx)
 
 	/* account for ctx->file reference (if in the table already) */
 	ckpt_obj_users_inc(ctx, ctx->file, 1);
+	if (ctx->logfile)
+		ckpt_obj_users_inc(ctx, ctx->logfile, 1);
 	/* account for ctx->root_nsproxy reference (if in the table already) */
 	ckpt_obj_users_inc(ctx, ctx->root_nsproxy, 1);
 
diff --git a/checkpoint/sys.c b/checkpoint/sys.c
index f50167a..dddf1a8 100644
--- a/checkpoint/sys.c
+++ b/checkpoint/sys.c
@@ -204,6 +204,8 @@ static void ckpt_ctx_free(struct ckpt_ctx *ctx)
 
 	if (ctx->file)
 		fput(ctx->file);
+	if (ctx->logfile)
+		fput(ctx->logfile);
 
 	ckpt_obj_hash_free(ctx);
 	path_put(&ctx->fs_mnt);
@@ -225,7 +227,7 @@ static void ckpt_ctx_free(struct ckpt_ctx *ctx)
 }
 
 static struct ckpt_ctx *ckpt_ctx_alloc(int fd, unsigned long uflags,
-				       unsigned long kflags)
+				       unsigned long kflags, int logfd)
 {
 	struct ckpt_ctx *ctx;
 	int err;
@@ -256,6 +258,13 @@ static struct ckpt_ctx *ckpt_ctx_alloc(int fd, unsigned long uflags,
 	if (!ctx->file)
 		goto err;
 
+	if (logfd == -1)
+		goto skiplogfd;
+	ctx->logfile = fget(logfd);
+	if (!ctx->logfile)
+		goto err;
+
+skiplogfd:
 	err = -ENOMEM;
 	if (ckpt_obj_hash_alloc(ctx) < 0)
 		goto err;
@@ -479,14 +488,13 @@ void _ckpt_msg_complete(struct ckpt_ctx *ctx)
 			printk(KERN_NOTICE "c/r: error string unsaved (%d): %s\n",
 			       ret, ctx->msg+1);
 	}
-#if 0
+
 	if (ctx->logfile) {
 		mm_segment_t fs = get_fs();
 		set_fs(KERNEL_DS);
 		ret = _ckpt_kwrite(ctx->logfile, ctx->msg+1, ctx->msglen-1);
 		set_fs(fs);
 	}
-#endif
 #ifdef CONFIG_CHECKPOINT_DEBUG
 	printk(KERN_DEBUG "%s", ctx->msg+1);
 #endif
@@ -520,11 +528,13 @@ void do_ckpt_msg(struct ckpt_ctx *ctx, char *fmt, ...)
  * @pid: pid of the container init(1) process
  * @fd: file to which dump the checkpoint image
  * @flags: checkpoint operation flags
+ * @logfd: fd to which to dump debug and error messages
  *
  * Returns positive identifier on success, 0 when returning from restart
  * or negative value on error
  */
-SYSCALL_DEFINE3(checkpoint, pid_t, pid, int, fd, unsigned long, flags)
+SYSCALL_DEFINE4(checkpoint, pid_t, pid, int, fd, unsigned long, flags,
+		int, logfd)
 {
 	struct ckpt_ctx *ctx;
 	long ret;
@@ -537,7 +547,7 @@ SYSCALL_DEFINE3(checkpoint, pid_t, pid, int, fd, unsigned long, flags)
 
 	if (pid == 0)
 		pid = task_pid_vnr(current);
-	ctx = ckpt_ctx_alloc(fd, flags, CKPT_CTX_CHECKPOINT);
+	ctx = ckpt_ctx_alloc(fd, flags, CKPT_CTX_CHECKPOINT, logfd);
 	if (IS_ERR(ctx))
 		return PTR_ERR(ctx);
 
@@ -555,11 +565,12 @@ SYSCALL_DEFINE3(checkpoint, pid_t, pid, int, fd, unsigned long, flags)
  * @pid: pid of task root (in coordinator's namespace), or 0
  * @fd: file from which read the checkpoint image
  * @flags: restart operation flags
+ * @logfd: fd to which to dump debug and error messages
  *
  * Returns negative value on error, or otherwise returns in the realm
  * of the original checkpoint
  */
-SYSCALL_DEFINE3(restart, pid_t, pid, int, fd, unsigned long, flags)
+SYSCALL_DEFINE4(restart, pid_t, pid, int, fd, unsigned long, flags, int, logfd)
 {
 	struct ckpt_ctx *ctx = NULL;
 	long ret;
@@ -572,7 +583,7 @@ SYSCALL_DEFINE3(restart, pid_t, pid, int, fd, unsigned long, flags)
 		return -EPERM;
 
 	if (pid)
-		ctx = ckpt_ctx_alloc(fd, flags, CKPT_CTX_RESTART);
+		ctx = ckpt_ctx_alloc(fd, flags, CKPT_CTX_RESTART, logfd);
 	if (IS_ERR(ctx))
 		return PTR_ERR(ctx);
 
diff --git a/include/linux/checkpoint_types.h b/include/linux/checkpoint_types.h
index 6771b9f..3c5e9f1 100644
--- a/include/linux/checkpoint_types.h
+++ b/include/linux/checkpoint_types.h
@@ -48,6 +48,7 @@ struct ckpt_ctx {
 	unsigned long oflags;	/* restart: uflags from checkpoint */
 
 	struct file *file;	/* input/output file */
+	struct file *logfile;	/* debug log file */
 	loff_t total;		/* total read/written */
 
 	atomic_t refcount;
diff --git a/include/linux/syscalls.h b/include/linux/syscalls.h
index 33bce6e..4fce331 100644
--- a/include/linux/syscalls.h
+++ b/include/linux/syscalls.h
@@ -754,8 +754,9 @@ asmlinkage long sys_pselect6(int, fd_set __user *, fd_set __user *,
 asmlinkage long sys_ppoll(struct pollfd __user *, unsigned int,
 			  struct timespec __user *, const sigset_t __user *,
 			  size_t);
-asmlinkage long sys_checkpoint(pid_t pid, int fd, unsigned long flags);
-asmlinkage long sys_restart(pid_t pid, int fd, unsigned long flags);
+asmlinkage long sys_checkpoint(pid_t pid, int fd, unsigned long flags,
+			       int logfd);
+asmlinkage long sys_restart(pid_t pid, int fd, unsigned long flags, int logfd);
 
 int kernel_execve(const char *filename, char *const argv[], char *const envp[]);
 
-- 
1.6.1

Re: [PATCH 01/12] define a new set of functions for error and debug logging

[Matt Helsley]

On Mon, Nov 02, 2009 at 04:23:29PM -0600, serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org wrote:
> From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

<snip>

> +/*
> + * _ckpt_generate_fmt - handle the special flags in the enhanced format
> + * strings used by checkpoint/restart error messages.

<snip>

> + *	ckpt_write_err(ctx, "%(T)FILE flags %d %O %E\n", flags, objref, err);
> + *
> + * Must be called with ctx->fmt_buf_lock held.  The expanded format
> + * will be placed in ctx->fmt_buf.

nit:

I haven't gotten through the series but this looks like either a stale
comment (re: "ctx->fmt_buf_lock"), or it's premature -- I don't see you
introduce or use this lock in this patch.

> + */
> +void _ckpt_generate_fmt(struct ckpt_ctx *ctx, char *fmt)
> +{
> +	char *s = ctx->fmt;
> +	int len = 0;
> +	int first = 1;
> +
> +	for (; *fmt && len < CKPT_MSG_LEN; fmt++) {
> +		if (!is_special_flag(fmt)) {
> +			s[len++] = *fmt;
> +			continue;
> +		}
> +		if (!first)
> +			s[len++] = ' ';
> +		else
> +			first = 0;

I'm tempted to say leave the space out. The square brackets delimit
these enough. And if the caller really needs the space then it can be
done: "%(E) %(O)foo".

<snip>

> +void _ckpt_msg_append(struct ckpt_ctx *ctx, char *fmt, ...)
> +{
> +	va_list ap;
> +
> +	va_start(ap, fmt);
> +	_ckpt_msg_appendv(ctx, fmt, ap);
> +	va_end(ap);
> +}
> +
> +void _ckpt_msg_complete(struct ckpt_ctx *ctx)
> +{
> +	int ret;

In the case of do_ckpt_msg() it's clear this won't happen. However
since _do_ckpt_msg() is separate from _ckpt_msg_complete() (looking
at the second patch) it's not clear that this will always be maintained
correctly.

BUG_ON(ctx->msglen < 1); /* detect msg_complete calls without any
				messages */

> +
> +	if (ctx->kflags & CKPT_CTX_CHECKPOINT) {
> +		ret = ckpt_write_obj_type(ctx, NULL, 0, CKPT_HDR_ERROR);
> +		if (!ret)
> +			ret = ckpt_write_string(ctx, ctx->msg, ctx->msglen);
> +		if (ret < 0)
> +			printk(KERN_NOTICE "c/r: error string unsaved (%d): %s\n",
> +			       ret, ctx->msg+1);
> +	}
> +#if 0
> +	if (ctx->logfile) {
> +		mm_segment_t fs = get_fs();
> +		set_fs(KERNEL_DS);
> +		ret = _ckpt_kwrite(ctx->logfile, ctx->msg+1, ctx->msglen-1);
> +		set_fs(fs);
> +	}
> +#endif
> +#ifdef CONFIG_CHECKPOINT_DEBUG
> +	printk(KERN_DEBUG "%s", ctx->msg+1);
> +#endif

Then clear:

	ctx->msglen = 0;

<snip>

> +/*
> + * Expand fmt into ctx->fmt.
> + * This expands enhanced format flags such as %(T), which takes no
> + * arguments, and %(E), which will require a properly positioned
> + * int error argument.  Flags include:
> + *   T: Task
> + *   E: Errno
> + *   O: Objref
> + *   P: Pointer
> + *   S: string
> + *   V: Variable (symbol)
> + * May be called under spinlock.
> + * Must be called under ckpt_msg_lock.
> + */
> +extern void _ckpt_generate_fmt(struct ckpt_ctx *ctx, char *fmt);

I'm not seeing why this is needed outside checkpoint/sys.c. In a future
patch?

<snip>

> +#define _ckpt_err(ctx, fmt, args...) do { \
> +	_do_ckpt_msg(ctx, "[ error %s:%d]" fmt, __func__, __LINE__, ##args);	\
> +} while (0)
> +
> +/* ckpt_logmsg() or ckpt_msg() will do do_ckpt_msg with an added
> + * prefix */

nit: This comment is about future code. It should perhaps be part of
	the patch description rather than in the code as comment.

<snip>

Re: [PATCH 01/12] define a new set of functions for error and debug logging

[Serge E. Hallyn]

Quoting Matt Helsley (matthltc-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org):
> On Mon, Nov 02, 2009 at 04:23:29PM -0600, serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org wrote:
> > From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
...
> I haven't gotten through the series but this looks like either a stale
> comment (re: "ctx->fmt_buf_lock"), or it's premature -- I don't see you
> introduce or use this lock in this patch.

Yup, stale comment, thanks.  No fmt_buf_lock this time around.

> > + */
> > +void _ckpt_generate_fmt(struct ckpt_ctx *ctx, char *fmt)
> > +{
> > +	char *s = ctx->fmt;
> > +	int len = 0;
> > +	int first = 1;
> > +
> > +	for (; *fmt && len < CKPT_MSG_LEN; fmt++) {
> > +		if (!is_special_flag(fmt)) {
> > +			s[len++] = *fmt;
> > +			continue;
> > +		}
> > +		if (!first)
> > +			s[len++] = ' ';
> > +		else
> > +			first = 0;
> 
> I'm tempted to say leave the space out. The square brackets delimit
> these enough. And if the caller really needs the space then it can be
> done: "%(E) %(O)foo".

Works for me.

> > +void _ckpt_msg_append(struct ckpt_ctx *ctx, char *fmt, ...)
> > +{
> > +	va_list ap;
> > +
> > +	va_start(ap, fmt);
> > +	_ckpt_msg_appendv(ctx, fmt, ap);
> > +	va_end(ap);
> > +}
> > +
> > +void _ckpt_msg_complete(struct ckpt_ctx *ctx)
> > +{
> > +	int ret;
> 
> In the case of do_ckpt_msg() it's clear this won't happen. However
> since _do_ckpt_msg() is separate from _ckpt_msg_complete() (looking
> at the second patch) it's not clear that this will always be maintained
> correctly.
> 
> BUG_ON(ctx->msglen < 1); /* detect msg_complete calls without any
> 				messages */

Well, just return if ctx->msglen < 1, but point taken, will fix.

> 
> > +
> > +	if (ctx->kflags & CKPT_CTX_CHECKPOINT) {
> > +		ret = ckpt_write_obj_type(ctx, NULL, 0, CKPT_HDR_ERROR);
> > +		if (!ret)
> > +			ret = ckpt_write_string(ctx, ctx->msg, ctx->msglen);
> > +		if (ret < 0)
> > +			printk(KERN_NOTICE "c/r: error string unsaved (%d): %s\n",
> > +			       ret, ctx->msg+1);
> > +	}
> > +#if 0
> > +	if (ctx->logfile) {
> > +		mm_segment_t fs = get_fs();
> > +		set_fs(KERNEL_DS);
> > +		ret = _ckpt_kwrite(ctx->logfile, ctx->msg+1, ctx->msglen-1);
> > +		set_fs(fs);
> > +	}
> > +#endif
> > +#ifdef CONFIG_CHECKPOINT_DEBUG
> > +	printk(KERN_DEBUG "%s", ctx->msg+1);
> > +#endif
> 
> Then clear:
> 
> 	ctx->msglen = 0;
> 
> <snip>
> 
> > +/*
> > + * Expand fmt into ctx->fmt.
> > + * This expands enhanced format flags such as %(T), which takes no
> > + * arguments, and %(E), which will require a properly positioned
> > + * int error argument.  Flags include:
> > + *   T: Task
> > + *   E: Errno
> > + *   O: Objref
> > + *   P: Pointer
> > + *   S: string
> > + *   V: Variable (symbol)
> > + * May be called under spinlock.
> > + * Must be called under ckpt_msg_lock.
> > + */
> > +extern void _ckpt_generate_fmt(struct ckpt_ctx *ctx, char *fmt);
> 
> I'm not seeing why this is needed outside checkpoint/sys.c. In a future
> patch?

Hmm, no...  in an earlier patchset.  I don't think there will be any
external callers of this fn.  Should be static.

> > +#define _ckpt_err(ctx, fmt, args...) do { \
> > +	_do_ckpt_msg(ctx, "[ error %s:%d]" fmt, __func__, __LINE__, ##args);	\
> > +} while (0)
> > +
> > +/* ckpt_logmsg() or ckpt_msg() will do do_ckpt_msg with an added
> > + * prefix */
> 
> nit: This comment is about future code. It should perhaps be part of
> 	the patch description rather than in the code as comment.

Sure - and if there are no basic objectiosn then apart from addressing
these I'll also aim to put some meaningful ckpt_errs() on restart failure
paths tomorrow.

thanks,
-serge

Re: [PATCH 01/12] define a new set of functions for error and debug logging

[Matt Helsley]

On Mon, Nov 02, 2009 at 08:39:59PM -0600, Serge E. Hallyn wrote:
> Quoting Matt Helsley (matthltc-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org):
> > On Mon, Nov 02, 2009 at 04:23:29PM -0600, serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org wrote:
> > > From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
> ...

<snip>

> > > +#define _ckpt_err(ctx, fmt, args...) do { \
> > > +	_do_ckpt_msg(ctx, "[ error %s:%d]" fmt, __func__, __LINE__, ##args);	\
> > > +} while (0)
> > > +
> > > +/* ckpt_logmsg() or ckpt_msg() will do do_ckpt_msg with an added
> > > + * prefix */
> > 
> > nit: This comment is about future code. It should perhaps be part of
> > 	the patch description rather than in the code as comment.
> 
> Sure - and if there are no basic objectiosn then apart from addressing
> these I'll also aim to put some meaningful ckpt_errs() on restart failure
> paths tomorrow.

No objections from me.

Acked-by: Matt Helsley <matthltc-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

Cheers,
	-Matt Helsley

Re: [PATCH 00/12] Standardize c/r error reporting (v3)

[Oren Laadan]

serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org wrote:
> From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
> 
> Here is a completely new approach, basically verbatim implementing
> Oren's recipe from last Friday.  It only implements the error part
> to replace ckpt_write_err.  The intent would be for ckpt_debug to
> also be replaced by ckpt_msg() which would be similar to ckpt_err()
> except adding a prefix to the message.
> 
> My goal is for users to be able to get real errors printed to a logfile
> for checkpoint and restart (not have to check dmesg) in ckpt-v19,
> especially for things like 'oh you're on a btrfs which is not supported'.
> Having to check dmesg seems to walk right into the 'toy implementation'
> argument.
> 
> Thanks Oren for the detailed explanation of what you want to see, and
> Matt for several excellent cleanup suggestions.
> 
> If there are no major objections then I'll add ckpt_err()s at restart
> on top of this patchset, but probably hold off on converting ckpt_debugs
> for a bit.  Note that the heavyweight semaphore means that for real
> debugging we're only increasing the chances of hiding bugs with the
> debugging, so I'm open to the idea of keeping ckpt_debug() as is.

"Heavyweight semaphore" ?

Maybe also mention that during checkpoint only one process uses this
interface - no contention;  During restart, for the most part, one
process runs at a time, except when transferring control to the the
next process in line - contention unlikely too.

Oren.

Re: [PATCH 01/12] define a new set of functions for error and debug logging

[Oren Laadan]

serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org wrote:
> From: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>
> 
> The checkpoint context now includes buffers for an expanded
> format and for messages to be written out.  A mutex protects
> these buffers as they are being built up and written out.
> ckpt_msg() will write general informative (debug) messages to
> syslog and an optional user-provided logfile.  ckpt_err() will
> write errors to the same places, and, if it is a checkpoint
> operation, also to the checkpoint image.
> 
> (This is intended to implement Oren's suggestion verbatim)
> 
> Signed-off-by: Serge E. Hallyn <serue-r/Jw6+rmf7HQT0dZR+AlfA@public.gmane.org>

[...]

> +void _ckpt_msg_complete(struct ckpt_ctx *ctx)
> +{
> +	int ret;
> +
> +	if (ctx->kflags & CKPT_CTX_CHECKPOINT) {
> +		ret = ckpt_write_obj_type(ctx, NULL, 0, CKPT_HDR_ERROR);

The _ckpt_msg_... interface is (will be?) used also for non-errors.
So writing and error record should also depend on ctx->errno, to be
set by someone before (ckpt_err ?)

> +		if (!ret)
> +			ret = ckpt_write_string(ctx, ctx->msg, ctx->msglen);
> +		if (ret < 0)
> +			printk(KERN_NOTICE "c/r: error string unsaved (%d): %s\n",
> +			       ret, ctx->msg+1);
> +	}
> +#if 0
> +	if (ctx->logfile) {
> +		mm_segment_t fs = get_fs();
> +		set_fs(KERNEL_DS);
> +		ret = _ckpt_kwrite(ctx->logfile, ctx->msg+1, ctx->msglen-1);
> +		set_fs(fs);
> +	}
> +#endif

This piece perhaps belongs to another patch ?

[...]

Oren.