Skip to contentSkip to conversation

Send checkpoint and restart debug info to a log file (v2)

RFC PATCH In review Serge E. Hallyn 4 participants 18 messages Oct 21, 2009 – Oct 26, 2009 13 messages not in the archive

Subsystems (12)
lore
Share & tools
lore
#0 lore raw

RFC PATCH 1/1 Send checkpoint and restart debug info to a log file (v2)

Until now, debug data was sent to syslog. That's not really right.

This patch sends ckpt_debug output to a logfile provided by the caller. If no logfile is provided, then no debug output is needed. So the user can pass in -1 for the logfd to say so.

Note that this does not address the potential (inevitable?) lockup of writing out a debug msg while checkpointing the debug file. In practice so far it seems to work rather well. (with quite a bit of testing)

This also means that we have to be more careful than we have been about not writing out sensitive data.

This is pure RFC, not meant to be pretty.

The split into ckpt_debug and ckpt_err (see changelog) suggests that we should rearrange (and be more consistent about) how and when we print out debug info. Left as an exercise for later.

Changelog:
Oct 21: split ckpt_debug into ckpt_debug and ckpt_err.
Git rid of the split by memory debug info etc. Since userspace actively asks for debug info, I also made it not depend on CONFIG_CHECKPOINT_DEBUG. We may want to put it back again to limit kernel size, but for now it's a distraction, and I'm not convinced it makes sense

---
 arch/s390/kernel/compat_wrapper.S |    2 +
 arch/x86/mm/checkpoint.c          |   11 ++---
 checkpoint/checkpoint.c           |   22 ++++----
 checkpoint/files.c                |   29 +++++------
 checkpoint/memory.c               |   43 ++++++++-------
 checkpoint/namespace.c            |    3 -
 checkpoint/objhash.c              |   33 +++++++------
 checkpoint/process.c              |   85 +++++++++++++++----------------
 checkpoint/restart.c              |  101 +++++++++++++++++--------------------
 checkpoint/signal.c               |    5 +--
 checkpoint/sys.c                  |   94 ++++++++++++++++++++++------------
 drivers/char/tty_io.c             |   22 ++++----
 include/linux/checkpoint.h        |   85 ++++++++++++++++---------------
 include/linux/checkpoint_types.h  |    5 +-
 include/linux/syscalls.h          |    5 +-
 ipc/checkpoint.c                  |   13 ++---
 ipc/checkpoint_msg.c              |   13 ++---
 ipc/checkpoint_sem.c              |   13 ++---
 ipc/checkpoint_shm.c              |   15 ++---
 kernel/cred.c                     |    2 +-
 lib/Kconfig.debug                 |    4 +-
 mm/filemap.c                      |    2 +-
 mm/shmem.c                        |    2 +-
 net/checkpoint.c                  |   46 ++++++++--------
 net/ipv4/checkpoint.c             |   26 ++++-----
 net/unix/checkpoint.c             |   65 +++++++++++++-----------
 26 files changed, 380 insertions(+), 366 deletions(-)
arch/s390/kernel/compat_wrapper.S +2 -0
index e882f99..414226e 100644
@@ -1846,6 +1846,7 @@ sys_checkpoint_wrapper:
 	lgfr	%r2,%r2			# pid_t
 	lgfr	%r3,%r3			# int
 	llgfr	%r4,%r4			# unsigned long
+	lgfr	%r5,%r5			# int
 	jg	compat_sys_checkpoint
 
 	.globl sys_restore_wrapper
@@ -1853,4 +1854,5 @@ sys_restore_wrapper:
 	lgfr	%r2,%r2			# int
 	lgfr	%r3,%r3			# int
 	llgfr	%r4,%r4			# unsigned long
+	lgfr	%r5,%r5			# int
 	jg	compat_sys_restore
arch/x86/mm/checkpoint.c +4 -7
index 9dd8e12..533e783 100644
@@ -8,9 +8,6 @@
  *  distribution for more details.
  */
 
-/* default debug level for output */
-#define CKPT_DFLAG  CKPT_DSYS
-
 #include <asm/desc.h>
 #include <asm/i387.h>
 #include <asm/elf.h>
@@ -292,7 +289,7 @@ int checkpoint_cpu(struct ckpt_ctx *ctx, struct task_struct *t)
 	save_cpu_debug(h, t);
 	save_cpu_fpu(h, t);
 
-	ckpt_debug("math %d debug %d\n", h->used_math, !!h->debugreg7);
+	ckpt_debug(ctx, "math %d debug %d\n", h->used_math, !!h->debugreg7);
 
 	ret = ckpt_write_obj(ctx, &h->h);
 	if (ret < 0)
@@ -341,7 +338,7 @@ int checkpoint_mm_context(struct ckpt_ctx *ctx, struct mm_struct *mm)
 	h->ldt_entry_size = LDT_ENTRY_SIZE;
 	h->nldt = mm->context.size;
 
-	ckpt_debug("nldt %d vdso %#llx\n", h->nldt, h->vdso);
+	ckpt_debug(ctx, "nldt %d vdso %#llx\n", h->nldt, h->vdso);
 
 	ret = ckpt_write_obj(ctx, &h->h);
 	ckpt_hdr_put(ctx, h);
@@ -522,7 +519,7 @@ int restore_cpu(struct ckpt_ctx *ctx)
 	if (IS_ERR(h))
 		return PTR_ERR(h);
 
-	ckpt_debug("math %d debug %d\n", h->used_math, !!h->debugreg7);
+	ckpt_debug(ctx, "math %d debug %d\n", h->used_math, !!h->debugreg7);
 
 	ret = load_cpu_regs(h, t);
 	if (ret < 0)
@@ -572,7 +569,7 @@ int restore_mm_context(struct ckpt_ctx *ctx, struct mm_struct *mm)
 	if (IS_ERR(h))
 		return PTR_ERR(h);
 
-	ckpt_debug("nldt %d vdso %#lx (%p)\n",
+	ckpt_debug(ctx, "nldt %d vdso %#lx (%p)\n",
 		 h->nldt, (unsigned long) h->vdso, mm->context.vdso);
 
 	ret = -EINVAL;
checkpoint/checkpoint.c +11 -11
index 6eb8f3b..883ccb9 100644
@@ -8,9 +8,6 @@
  *  distribution for more details.
  */
 
-/* default debug level for output */
-#define CKPT_DFLAG  CKPT_DSYS
-
 #include <linux/version.h>
 #include <linux/sched.h>
 #include <linux/freezer.h>
@@ -38,7 +35,7 @@ static atomic_t ctx_count = ATOMIC_INIT(0);
  */
 int ckpt_write_obj(struct ckpt_ctx *ctx, struct ckpt_hdr *h)
 {
-	_ckpt_debug(CKPT_DRW, "type %d len %d\n", h->type, h->len);
+	ckpt_debug(ctx, "type %d len %d\n", h->type, h->len);
 	return ckpt_kwrite(ctx, h, h->len);
 }
 
@@ -63,7 +60,7 @@ int ckpt_write_obj_type(struct ckpt_ctx *ctx, void *ptr, int len, int type)
 	h->type = type;
 	h->len = len + sizeof(*h);
 
-	_ckpt_debug(CKPT_DRW, "type %d len %d\n", h->type, h->len);
+	ckpt_debug(ctx, "type %d len %d\n", h->type, h->len);
 	ret = ckpt_kwrite(ctx, h, sizeof(*h));
 	if (ret < 0)
 		goto out;
@@ -213,7 +210,7 @@ static void __ckpt_generate_err(struct ckpt_ctx *ctx, char *fmt0,
 	va_end(aq);
 	kfree(format);
 
-	ckpt_debug("c/r: checkpoint error: %s\n", str);
+	ckpt_debug(ctx, "c/r: checkpoint error: %s\n", str);
 }
 
 /**
@@ -392,7 +389,7 @@ static int checkpoint_all_tasks(struct ckpt_ctx *ctx)
 	int n, ret = 0;
 
 	for (n = 0; n < ctx->nr_tasks; n++) {
-		ckpt_debug("dumping task #%d\n", n);
+		ckpt_debug(ctx, "dumping task #%d\n", n);
 		ret = checkpoint_task(ctx, ctx->tasks_arr[n]);
 		if (ret < 0)
 			break;
@@ -407,7 +404,8 @@ static int may_checkpoint_task(struct ckpt_ctx *ctx, struct task_struct *t)
 	struct nsproxy *nsproxy;
 	int ret = 0;
 
-	ckpt_debug("check %d\n", task_pid_nr_ns(t, ctx->root_nsproxy->pid_ns));
+	ckpt_debug(ctx, "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);
@@ -499,7 +497,8 @@ static int checkpoint_pids(struct ckpt_ctx *ctx)
 			h[n].vpgid = task_pgrp_nr_ns(task, ns);
 			h[n].vsid = task_session_nr_ns(task, ns);
 			h[n].vppid = task_tgid_nr_ns(task->real_parent, ns);
-			ckpt_debug("task[%d]: vpid %d vtgid %d parent %d\n",
+			ckpt_debug(ctx,
+				   "task[%d]: vpid %d vtgid %d parent %d\n",
 				   pos, h[n].vpid, h[n].vtgid, h[n].vppid);
 			pos++;
 		}
@@ -522,7 +521,7 @@ static int collect_objects(struct ckpt_ctx *ctx)
 	int n, ret = 0;
 
 	for (n = 0; n < ctx->nr_tasks; n++) {
-		ckpt_debug("dumping task #%d\n", n);
+		ckpt_debug(ctx, "dumping task #%d\n", n);
 		ret = ckpt_collect_task(ctx, ctx->tasks_arr[n]);
 		if (ret < 0) {
 			ctx->tsk = ctx->tasks_arr[n];
@@ -579,7 +578,8 @@ static int tree_count_tasks(struct ckpt_ctx *ctx)
 	data.ctx = ctx;
 	data.nr = 0;
 
-	return walk_task_subtree(ctx->root_task, __tree_count_tasks, &data);
+	return walk_task_subtree(ctx, ctx->root_task, __tree_count_tasks,
+				 &data);
 }
 
 /*
checkpoint/files.c +14 -15
index f6de07e..44b8db0 100644
@@ -8,9 +8,6 @@
  *  distribution for more details.
  */
 
-/* default debug level for output */
-#define CKPT_DFLAG  CKPT_DFILE
-
 #include <linux/kernel.h>
 #include <linux/module.h>
 #include <linux/sched.h>
@@ -159,7 +156,7 @@ int checkpoint_file_common(struct ckpt_ctx *ctx, struct file *file,
 	if (h->f_credref < 0)
 		return h->f_credref;
 
-	ckpt_debug("file %s credref %d", file->f_dentry->d_name.name,
+	ckpt_debug(ctx, "file %s credref %d", file->f_dentry->d_name.name,
 		h->f_credref);
 
 	/* FIX: need also file->f_owner, etc */
@@ -204,12 +201,13 @@ int checkpoint_file(struct ckpt_ctx *ctx, void *ptr)
 	if (!file->f_op || !file->f_op->checkpoint) {
 		ckpt_write_err(ctx, "TEPS", "f_op lacks checkpoint",
 			       -EBADF, file, file->f_op);
-		ckpt_debug("f_op lacks checkpoint handler: %pS\n", file->f_op);
+		ckpt_err(ctx, "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_debug("unlinked files are unsupported\n");
+		ckpt_err(ctx, "unlinked files are unsupported\n");
 		return -EBADF;
 	}
 
@@ -264,7 +262,8 @@ static int checkpoint_file_desc(struct ckpt_ctx *ctx,
 	 * a reference to it, dump its state while at it.
 	 */
 	objref = checkpoint_obj(ctx, file, CKPT_OBJ_FILE);
-	ckpt_debug("fd %d objref %d file %p coe %d)\n", fd, objref, file, coe);
+	ckpt_debug(ctx, "fd %d objref %d file %p coe %d)\n", fd, objref, file,
+		   coe);
 	if (objref < 0) {
 		ret = objref;
 		goto out;
@@ -306,7 +305,7 @@ static int do_checkpoint_file_table(struct ckpt_ctx *ctx,
 	if (ret < 0)
 		goto out;
 
-	ckpt_debug("nfds %d\n", nfds);
+	ckpt_debug(ctx, "nfds %d\n", nfds);
 	for (n = 0; n < nfds; n++) {
 		ret = checkpoint_file_desc(ctx, files, fdtable[n]);
 		if (ret < 0)
@@ -314,7 +313,7 @@ static int do_checkpoint_file_table(struct ckpt_ctx *ctx,
 	}
 
 	ret = deferqueue_run(ctx->files_deferq);
-	ckpt_debug("files_deferq ran %d entries\n", ret);
+	ckpt_debug(ctx, "files_deferq ran %d entries\n", ret);
 	if (ret > 0)
 		ret = 0;
  out:
@@ -452,7 +451,7 @@ struct file *restore_open_fname(struct ckpt_ctx *ctx, int flags)
 	if (IS_ERR(h))
 		return (struct file *) h;
 	fname = (char *) (h + 1);
-	ckpt_debug("fname '%s' flags %#x\n", fname, flags);
+	ckpt_debug(ctx, "fname '%s' flags %#x\n", fname, flags);
 
 	file = filp_open(fname, flags, 0);
 	ckpt_hdr_put(ctx, h);
@@ -623,7 +622,7 @@ static struct file *do_restore_file(struct ckpt_ctx *ctx)
 	h = ckpt_read_buf_type(ctx, PAGE_SIZE, CKPT_HDR_FILE);
 	if (IS_ERR(h))
 		return (struct file *) h;
-	ckpt_debug("flags %#x mode %#x type %d\n",
+	ckpt_debug(ctx, "flags %#x mode %#x type %d\n",
 		 h->f_flags, h->f_mode, h->f_type);
 
 	if (h->f_type >= CKPT_FILE_MAX)
@@ -662,7 +661,7 @@ static int restore_file_desc(struct ckpt_ctx *ctx)
 	h = ckpt_read_obj_type(ctx, sizeof(*h), CKPT_HDR_FILE_DESC);
 	if (IS_ERR(h))
 		return PTR_ERR(h);
-	ckpt_debug("ref %d fd %d c.o.e %d\n",
+	ckpt_debug(ctx, "ref %d fd %d c.o.e %d\n",
 		 h->fd_objref, h->fd_descriptor, h->fd_close_on_exec);
 
 	ret = -EINVAL;
@@ -681,7 +680,7 @@ static int restore_file_desc(struct ckpt_ctx *ctx)
 		goto out;
 	}
 
-	ckpt_debug("newfd got %d wanted %d\n", newfd, h->fd_descriptor);
+	ckpt_debug(ctx, "newfd got %d wanted %d\n", newfd, h->fd_descriptor);
 
 	/* reposition if newfd isn't desired fd */
 	if (newfd != h->fd_descriptor) {
@@ -709,7 +708,7 @@ static struct files_struct *do_restore_file_table(struct ckpt_ctx *ctx)
 	if (IS_ERR(h))
 		return (struct files_struct *) h;
 
-	ckpt_debug("nfds %d\n", h->fdt_nfds);
+	ckpt_debug(ctx, "nfds %d\n", h->fdt_nfds);
 
 	ret = -EMFILE;
 	if (h->fdt_nfds < 0 || h->fdt_nfds > sysctl_nr_open)
@@ -734,7 +733,7 @@ static struct files_struct *do_restore_file_table(struct ckpt_ctx *ctx)
 	}
 
 	ret = deferqueue_run(ctx->files_deferq);
-	ckpt_debug("files_deferq ran %d entries\n", ret);
+	ckpt_debug(ctx, "files_deferq ran %d entries\n", ret);
 	if (ret > 0)
 		ret = 0;
  out:
checkpoint/memory.c +23 -20

146 lines not on this page · raw message

checkpoint/namespace.c +0 -3
index 89af2c0..5795bb8 100644
@@ -8,9 +8,6 @@
  *  distribution for more details.
  */
 
-/* default debug level for output */
-#define CKPT_DFLAG  CKPT_DSYS
-
 #include <linux/nsproxy.h>
 #include <linux/user_namespace.h>
 
checkpoint/objhash.c +18 -15
index 730dd82..89018e4 100644
@@ -8,9 +8,6 @@
  *  distribution for more details.
  */
 
-/* default debug level for output */
-#define CKPT_DFLAG  CKPT_DOBJ
-
 #include <linux/kernel.h>
 #include <linux/hash.h>
 #include <linux/file.h>
@@ -624,7 +621,7 @@ int ckpt_obj_collect(struct ckpt_ctx *ctx, void *ptr, enum obj_type type)
 	obj = obj_lookup_add(ctx, ptr, type, &first);
 	if (IS_ERR(obj))
 		return PTR_ERR(obj);
-	ckpt_debug("%s objref %d first %d\n",
+	ckpt_debug(ctx, "%s objref %d first %d\n",
 		   obj->ops->obj_name, obj->objref, first);
 	return (first ? obj->objref : 0);
 }
@@ -645,7 +642,8 @@ int ckpt_obj_lookup(struct ckpt_ctx *ctx, void *ptr, enum obj_type type)
 	obj = obj_find_by_ptr(ctx, ptr);
 	BUG_ON(obj && obj->ops->obj_type != type);
 	if (obj)
-		ckpt_debug("%s objref %d\n", obj->ops->obj_name, obj->objref);
+		ckpt_debug(ctx, "%s objref %d\n", obj->ops->obj_name,
+			   obj->objref);
 	return obj ? obj->objref : 0;
 }
 
@@ -682,7 +680,7 @@ int ckpt_obj_lookup_add(struct ckpt_ctx *ctx, void *ptr,
 	obj = obj_lookup_add(ctx, ptr, type, first);
 	if (IS_ERR(obj))
 		return PTR_ERR(obj);
-	ckpt_debug("%s objref %d first %d\n",
+	ckpt_debug(ctx, "%s objref %d first %d\n",
 		   obj->ops->obj_name, obj->objref, *first);
 
 	if (*first && obj_reverse_leak(ctx, obj))
@@ -780,7 +778,7 @@ int ckpt_obj_visit(struct ckpt_ctx *ctx, void *ptr, enum obj_type type)
 			return -EBUSY;
 		}
 	} else {
-		ckpt_debug("visit %s objref %d\n",
+		ckpt_debug(ctx, "visit %s objref %d\n",
 			   obj->ops->obj_name, obj->objref);
 		obj->flags |= CKPT_OBJ_VISITED;
 	}
@@ -823,6 +821,7 @@ static void ckpt_obj_users_inc(struct ckpt_ctx *ctx, void *ptr, int increment)
 
 /**
  * obj_sock_adjust_users - remove implicit reference on DEAD sockets
+ * @ctx: checkpoint context
  * @obj: CKPT_OBJ_SOCK object to adjust
  *
  * Sockets that have been disconnected from their struct file have
@@ -830,13 +829,14 @@ static void ckpt_obj_users_inc(struct ckpt_ctx *ctx, void *ptr, int increment)
  * assumption of such a reference is therefore incorrect, so we correct
  * it here.
  */
-static inline void obj_sock_adjust_users(struct ckpt_obj *obj)
+static inline void obj_sock_adjust_users(struct ckpt_ctx *ctx,
+					 struct ckpt_obj *obj)
 {
 	struct sock *sk = (struct sock *)obj->ptr;
 
 	if (sock_flag(sk, SOCK_DEAD)) {
 		obj->users--;
-		ckpt_debug("Adjusting SOCK %i count to %i\n",
+		ckpt_debug(ctx, "Adjusting SOCK %i count to %i\n",
 			   obj->objref, obj->users);
 	}
 }
@@ -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);
 
@@ -866,10 +868,10 @@ int ckpt_obj_contained(struct ckpt_ctx *ctx)
 			continue;
 
 		if (obj->ops->obj_type == CKPT_OBJ_SOCK)
-			obj_sock_adjust_users(obj);
+			obj_sock_adjust_users(ctx, obj);
 
 		if (obj->ops->ref_users(obj->ptr) != obj->users) {
-			ckpt_debug("usage leak: %s\n", obj->ops->obj_name);
+			ckpt_debug(ctx, "usage leak: %s\n", obj->ops->obj_name);
 			ckpt_write_err(ctx, "OP", "leak: usage (%d != %d (%s)",
 				       obj->objref, obj->ptr,
 				       obj->ops->ref_users(obj->ptr),
@@ -894,7 +896,7 @@ int ckpt_obj_visited(struct ckpt_ctx *ctx)
 
 	hlist_for_each_entry(obj, node, &ctx->obj_hash->list, next) {
 		if (!(obj->flags & CKPT_OBJ_VISITED)) {
-			ckpt_debug("reverse leak: %s (%d)\n",
+			ckpt_debug(ctx, "reverse leak: %s (%d)\n",
 				   obj->ops->obj_name, obj->objref);
 			ckpt_write_err(ctx, "OP", "leak: not visited (%s)",
 				       obj->objref, obj->ptr,
@@ -929,7 +931,8 @@ int restore_obj(struct ckpt_ctx *ctx, struct ckpt_hdr_objref *h)
 	struct ckpt_obj *obj;
 	void *ptr = NULL;
 
-	ckpt_debug("len %d ref %d type %d\n", h->h.len, h->objref, h->objtype);
+	ckpt_debug(ctx, "len %d ref %d type %d\n", h->h.len, h->objref,
+		   h->objtype);
 	if (h->objtype >= CKPT_OBJ_MAX)
 		return -EINVAL;
 	if (h->objref <= 0)
@@ -985,7 +988,7 @@ int ckpt_obj_insert(struct ckpt_ctx *ctx, void *ptr,
 	obj = obj_new(ctx, ptr, objref, type);
 	if (IS_ERR(obj))
 		return PTR_ERR(obj);
-	ckpt_debug("%s objref %d\n", obj->ops->obj_name, objref);
+	ckpt_debug(ctx, "%s objref %d\n", obj->ops->obj_name, objref);
 	return obj->objref;
 }
 
@@ -1007,6 +1010,6 @@ void *ckpt_obj_fetch(struct ckpt_ctx *ctx, int objref, enum obj_type type)
 	obj = obj_find_by_objref(ctx, objref);
 	if (!obj)
 		return ERR_PTR(-EINVAL);
-	ckpt_debug("%s ref %d\n", obj->ops->obj_name, obj->objref);
+	ckpt_debug(ctx, "%s ref %d\n", obj->ops->obj_name, obj->objref);
 	return (obj->ops->obj_type == type ? obj->ptr : ERR_PTR(-ENOMSG));
 }
checkpoint/process.c +41 -44

291 lines not on this page · raw message

checkpoint/restart.c +47 -54

318 lines not on this page · raw message

checkpoint/signal.c +1 -4
index cdfb142..97e878b 100644
@@ -8,9 +8,6 @@
  *  distribution for more details.
  */
 
-/* default debug level for output */
-#define CKPT_DFLAG  CKPT_DSYS
-
 #include <linux/sched.h>
 #include <linux/signal.h>
 #include <linux/errno.h>
@@ -367,7 +364,7 @@ static int checkpoint_signal(struct ckpt_ctx *ctx, struct task_struct *t)
 		 * the signal from this very expiry won't be sent before
 		 * we release t->sighand->siglock).
 		 */
-		ckpt_debug("active ! %lld\n", delta.tv64);
+		ckpt_debug(ctx, "active ! %lld\n", delta.tv64);
 		if (delta.tv64 <= 0)
 			delta.tv64 = NSEC_PER_USEC;
 		h->it_real_value = ktime_to_ns(delta);
checkpoint/sys.c +62 -32

160 lines not on this page · raw message

drivers/char/tty_io.c +11 -11
index 1b220c1..2fd2cd4 100644
@@ -2664,7 +2664,7 @@ static int tty_file_checkpoint(struct ckpt_ctx *ctx, struct file *file)
 	 */
 
 	real_tty = tty_pair_get_tty(tty);
-	ckpt_debug("tty: %p, real_tty: %p\n", tty, real_tty);
+	ckpt_debug(ctx, "tty: %p, real_tty: %p\n", tty, real_tty);
 
 	master_objref = checkpoint_obj(ctx, real_tty->link, CKPT_OBJ_TTY);
 	if (master_objref < 0)
@@ -2672,7 +2672,7 @@ static int tty_file_checkpoint(struct ckpt_ctx *ctx, struct file *file)
 	slave_objref = checkpoint_obj(ctx, real_tty, CKPT_OBJ_TTY);
 	if (slave_objref < 0)
 		return slave_objref;
-	ckpt_debug("master %p %d, slave %p %d\n",
+	ckpt_debug(ctx, "master %p %d, slave %p %d\n",
 		   real_tty->link, master_objref, real_tty, slave_objref);
 
 	h = ckpt_hdr_get_type(ctx, sizeof(*h), CKPT_HDR_FILE);
@@ -2704,7 +2704,7 @@ static int tty_file_collect(struct ckpt_ctx *ctx, struct file *file)
 	if (!tty_can_checkpoint(ctx, tty))
 		return -ENOSYS;
 
-	ckpt_debug("collecting tty: %p\n", tty);
+	ckpt_debug(ctx, "collecting tty: %p\n", tty);
 	ret = ckpt_obj_collect(ctx, tty, CKPT_OBJ_TTY);
 	if (ret < 0)
 		return ret;
@@ -2714,7 +2714,7 @@ static int tty_file_collect(struct ckpt_ctx *ctx, struct file *file)
 			ckpt_write_err(ctx, "TP", "tty: missing link\n", tty);
 			return -EIO;
 		}
-		ckpt_debug("collecting slave tty: %p\n", tty->link);
+		ckpt_debug(ctx, "collecting slave tty: %p\n", tty->link);
 		ret = ckpt_obj_collect(ctx, tty->link, CKPT_OBJ_TTY);
 	}
 
@@ -2781,7 +2781,7 @@ static int checkpoint_tty_ldisc(struct ckpt_ctx *ctx, struct tty_struct *tty)
 	if (ret < 0)
 		return ret;
 
-	ckpt_debug("datalen %d\n", datalen);
+	ckpt_debug(ctx, "datalen %d\n", datalen);
 	if (datalen) {
 		ret = ckpt_write_buffer(ctx, NULL, datalen);
 		if (ret < 0)
@@ -2836,7 +2836,7 @@ static int do_checkpoint_tty(struct ckpt_ctx *ctx, struct tty_struct *tty)
 
 	/* if master, reserve an objref (see do_restore_tty) */
 	h->file_objref = (master ? ckpt_obj_reserve(ctx) : 0);
-	ckpt_debug("link %d file %d\n", h->link_objref, h->file_objref);
+	ckpt_debug(ctx, "link %d file %d\n", h->link_objref, h->file_objref);
 
 	h->index = tty->index;
 	h->ldisc = tty->ldisc->ops->num;
@@ -2889,7 +2889,7 @@ struct file *tty_file_restore(struct ckpt_ctx *ctx, struct ckpt_hdr_file *ptr)
 		return ERR_PTR(-EINVAL);
 
 	tty = ckpt_obj_fetch(ctx, h->tty_objref, CKPT_OBJ_TTY);
-	ckpt_debug("tty %p objref %d\n", tty, h->tty_objref);
+	ckpt_debug(ctx, "tty %p objref %d\n", tty, h->tty_objref);
 
 	/* at this point the tty should have been restore already */
 	if (IS_ERR(tty))
@@ -2910,13 +2910,13 @@ struct file *tty_file_restore(struct ckpt_ctx *ctx, struct ckpt_hdr_file *ptr)
 					typeof(*file), f_u.fu_list);
 		get_file(file);
 		file_list_unlock();
-		ckpt_debug("master file %p\n", file);
+		ckpt_debug(ctx, "master file %p\n", file);
 	} else {
 		sprintf(slavepath, "/dev/pts/%d", tty->index);
 		slavelock = test_bit(TTY_PTY_LOCK, &tty->link->flags);
 		clear_bit(TTY_PTY_LOCK, &tty->link->flags);
 		file = filp_open(slavepath, O_RDWR | O_NOCTTY, 0);
-		ckpt_debug("slave file %p (idnex %d)\n", file, tty->index);
+		ckpt_debug(ctx, "slave file %p (idnex %d)\n", file, tty->index);
 		if (IS_ERR(file))
 			return file;
 		if (slavelock)
@@ -3026,7 +3026,7 @@ static struct tty_struct *do_restore_tty(struct ckpt_ctx *ctx)
 	if (test_bit(TTY_HUPPED, (unsigned long *) &h->flags) && master)
 		goto out;
 
-	ckpt_debug("sanity checks passed, link %d\n", h->link_objref);
+	ckpt_debug(ctx, "sanity checks passed, link %d\n", h->link_objref);
 
 	/*
 	 * If we ever support more than PTYs, this would be tty-type
@@ -3060,7 +3060,7 @@ static struct tty_struct *do_restore_tty(struct ckpt_ctx *ctx)
 		tty = tty->link;
 	}
 
-	ckpt_debug("tty %p (hup %d)\n",
+	ckpt_debug(ctx, "tty %p (hup %d)\n",
 		   tty, test_bit(TTY_HUPPED, (unsigned long *) &h->flags));
 
 	/* we now have the desired tty: restore its state as per @h */
include/linux/checkpoint.h +44 -41

132 lines not on this page · raw message

include/linux/checkpoint_types.h +3 -2
index fa57cdc..8182a9c 100644
@@ -47,8 +47,9 @@ struct ckpt_ctx {
 	unsigned long uflags;	/* user flags */
 	unsigned long oflags;	/* restart: uflags from checkpoint */
 
-	struct file *file;	/* input/output file */
-	int total;		/* total read/written */
+	struct file *file;		/* input/output file */
+	struct file *logfile;	/* debug log file */
+	int total;			/* total read/written */
 
 	atomic_t refcount;
 
include/linux/syscalls.h +3 -2
index 33bce6e..c460d87 100644
@@ -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[]);
 
ipc/checkpoint.c +6 -7
index 8e6e9ba..65863a8 100644
@@ -8,9 +8,6 @@
  *  distribution for more details.
  */
 
-/* default debug level for output */
-#define CKPT_DFLAG  CKPT_DIPC
-
 #include <linux/ipc.h>
 #include <linux/msg.h>
 #include <linux/sched.h>
@@ -65,7 +62,8 @@ static int checkpoint_ipc_any(struct ckpt_ctx *ctx,
 
 	h->ipc_type = ipc_type;
 	h->ipc_count = ipc_ids->in_use;
-	ckpt_debug("ipc-%s count %d\n", ipc_ind_to_str[ipc_ind], h->ipc_count);
+	ckpt_debug(ctx, "ipc-%s count %d\n", ipc_ind_to_str[ipc_ind],
+		   h->ipc_count);
 
 	ret = ckpt_write_obj(ctx, &h->h);
 	ckpt_hdr_put(ctx, h);
@@ -73,7 +71,7 @@ static int checkpoint_ipc_any(struct ckpt_ctx *ctx,
 		goto out;
 
 	ret = idr_for_each(&ipc_ids->ipcs_idr, func, ctx);
-	ckpt_debug("ipc-%s ret %d\n", ipc_ind_to_str[ipc_ind], ret);
+	ckpt_debug(ctx, "ipc-%s ret %d\n", ipc_ind_to_str[ipc_ind], ret);
  out:
 	up_read(&ipc_ids->rw_mutex);
 	return ret;
@@ -229,7 +227,8 @@ static int restore_ipc_any(struct ckpt_ctx *ctx, struct ipc_namespace *ipc_ns,
 	if (IS_ERR(h))
 		return PTR_ERR(h);
 
-	ckpt_debug("ipc-%s: count %d\n", ipc_ind_to_str[ipc_ind], h->ipc_count);
+	ckpt_debug(ctx, "ipc-%s: count %d\n", ipc_ind_to_str[ipc_ind],
+		   h->ipc_count);
 
 	ret = -EINVAL;
 	if (h->ipc_type != ipc_type)
@@ -242,7 +241,7 @@ static int restore_ipc_any(struct ckpt_ctx *ctx, struct ipc_namespace *ipc_ns,
 			goto out;
 	}
  out:
-	ckpt_debug("ipc-%s: ret %d\n", ipc_ind_to_str[ipc_ind], ret);
+	ckpt_debug(ctx, "ipc-%s: ret %d\n", ipc_ind_to_str[ipc_ind], ret);
 	ckpt_hdr_put(ctx, h);
 	return ret;
 }
ipc/checkpoint_msg.c +5 -8
index b933c19..8c2233e 100644
@@ -8,9 +8,6 @@
  *  distribution for more details.
  */
 
-/* default debug level for output */
-#define CKPT_DFLAG  CKPT_DIPC
-
 #include <linux/mm.h>
 #include <linux/msg.h>
 #include <linux/rwsem.h>
@@ -52,7 +49,7 @@ static int fill_ipc_msg_hdr(struct ckpt_ctx *ctx,
 
  unlock:
 	ipc_unlock(&msq->q_perm);
-	ckpt_debug("msg: lspid %d rspid %d qnum %lld qbytes %lld\n",
+	ckpt_debug(ctx, "msg: lspid %d rspid %d qnum %lld qbytes %lld\n",
 		 h->q_lspid, h->q_lrpid, h->q_qnum, h->q_qbytes);
 
 	return ret;
@@ -181,7 +178,7 @@ static int load_ipc_msg_hdr(struct ckpt_ctx *ctx,
 	if (ret < 0)
 		return ret;
 
-	ckpt_debug("msq: lspid %d lrpid %d qnum %lld qbytes %lld\n",
+	ckpt_debug(ctx, "msq: lspid %d lrpid %d qnum %lld qbytes %lld\n",
 		 h->q_lspid, h->q_lrpid, h->q_qnum, h->q_qbytes);
 
 	if (h->q_lspid < 0 || h->q_lrpid < 0)
@@ -323,10 +320,10 @@ int restore_ipc_msg(struct ckpt_ctx *ctx, struct ipc_namespace *ns)
 
 	/* restore the message queue */
 	msgflag = h->perms.mode | IPC_CREAT | IPC_EXCL;
-	ckpt_debug("msg: do_msgget key %d flag %#x id %d\n",
+	ckpt_debug(ctx, "msg: do_msgget key %d flag %#x id %d\n",
 		 h->perms.key, msgflag, h->perms.id);
 	ret = do_msgget(ns, h->perms.key, msgflag, h->perms.id);
-	ckpt_debug("msg: do_msgget ret %d\n", ret);
+	ckpt_debug(ctx, "msg: do_msgget ret %d\n", ret);
 	if (ret < 0)
 		goto out;
 
@@ -352,7 +349,7 @@ int restore_ipc_msg(struct ckpt_ctx *ctx, struct ipc_namespace *ns)
 	ret = load_ipc_msg_hdr(ctx, h, msq);
 
 	if (ret < 0) {
-		ckpt_debug("msq: need to remove (%d)\n", ret);
+		ckpt_err(ctx, "msq: need to remove (%d)\n", ret);
 		freeque(ns, perms);
 	} else
 		ipc_unlock(perms);
ipc/checkpoint_sem.c +5 -8
index 76eb2b9..06f59f6 100644
@@ -8,9 +8,6 @@
  *  distribution for more details.
  */
 
-/* default debug level for output */
-#define CKPT_DFLAG  CKPT_DIPC
-
 #include <linux/mm.h>
 #include <linux/sem.h>
 #include <linux/rwsem.h>
@@ -47,7 +44,7 @@ static int fill_ipc_sem_hdr(struct ckpt_ctx *ctx,
 
  unlock:
 	ipc_unlock(&sem->sem_perm);
-	ckpt_debug("sem: nsems %u\n", h->sem_nsems);
+	ckpt_debug(ctx, "sem: nsems %u\n", h->sem_nsems);
 
 	return ret;
 }
@@ -117,7 +114,7 @@ static int load_ipc_sem_hdr(struct ckpt_ctx *ctx,
 	if (ret < 0)
 		return ret;
 
-	ckpt_debug("sem: nsems %u\n", h->sem_nsems);
+	ckpt_debug(ctx, "sem: nsems %u\n", h->sem_nsems);
 
 	sem->sem_otime = h->sem_otime;
 	sem->sem_ctime = h->sem_ctime;
@@ -191,10 +188,10 @@ int restore_ipc_sem(struct ckpt_ctx *ctx, struct ipc_namespace *ns)
 
 	/* restore the message queue now */
 	semflag = h->perms.mode | IPC_CREAT | IPC_EXCL;
-	ckpt_debug("sem: do_semget key %d flag %#x id %d\n",
+	ckpt_debug(ctx, "sem: do_semget key %d flag %#x id %d\n",
 		 h->perms.key, semflag, h->perms.id);
 	ret = do_semget(ns, h->perms.key, h->sem_nsems, semflag, h->perms.id);
-	ckpt_debug("sem: do_semget ret %d\n", ret);
+	ckpt_debug(ctx, "sem: do_semget ret %d\n", ret);
 	if (ret < 0)
 		goto out;
 
@@ -209,7 +206,7 @@ int restore_ipc_sem(struct ckpt_ctx *ctx, struct ipc_namespace *ns)
 
 	ret = load_ipc_sem_hdr(ctx, h, sem);
 	if (ret < 0) {
-		ckpt_debug("sem: need to remove (%d)\n", ret);
+		ckpt_err(ctx, "sem: need to remove (%d)\n", ret);
 		freeary(ns, perms);
 	} else
 		ipc_unlock(perms);
ipc/checkpoint_shm.c +6 -9
index 826e430..92523f0 100644
@@ -8,9 +8,6 @@
  *  distribution for more details.
  */
 
-/* default debug level for output */
-#define CKPT_DFLAG  CKPT_DIPC
-
 #include <linux/mm.h>
 #include <linux/shm.h>
 #include <linux/shmem_fs.h>
@@ -69,7 +66,7 @@ static int fill_ipc_shm_hdr(struct ckpt_ctx *ctx,
 
  unlock:
 	ipc_unlock(&shp->shm_perm);
-	ckpt_debug("shm: cprid %d lprid %d segsz %lld mlock %d\n",
+	ckpt_debug(ctx, "shm: cprid %d lprid %d segsz %lld mlock %d\n",
 		 h->shm_cprid, h->shm_lprid, h->shm_segsz, h->mlock_uid);
 
 	return ret;
@@ -106,7 +103,7 @@ int checkpoint_ipc_shm(int id, void *p, void *data)
 		goto out;
 
 	h->objref = objref;
-	ckpt_debug("shm: objref %d\n", h->objref);
+	ckpt_debug(ctx, "shm: objref %d\n", h->objref);
 
 	ret = ckpt_write_obj(ctx, &h->h);
 	if (ret < 0)
@@ -169,7 +166,7 @@ static int load_ipc_shm_hdr(struct ckpt_ctx *ctx,
 	if (ret < 0)
 		return ret;
 
-	ckpt_debug("shm: cprid %d lprid %d segsz %lld mlock %d\n",
+	ckpt_debug(ctx, "shm: cprid %d lprid %d segsz %lld mlock %d\n",
 		 h->shm_cprid, h->shm_lprid, h->shm_segsz, h->mlock_uid);
 
 	if (h->shm_cprid < 0 || h->shm_lprid < 0)
@@ -237,10 +234,10 @@ int restore_ipc_shm(struct ckpt_ctx *ctx, struct ipc_namespace *ns)
 	}
 
 	shmflag = h->flags | h->perms.mode | IPC_CREAT | IPC_EXCL;
-	ckpt_debug("shm: do_shmget size %lld flag %#x id %d\n",
+	ckpt_debug(ctx, "shm: do_shmget size %lld flag %#x id %d\n",
 		 h->shm_segsz, shmflag, h->perms.id);
 	ret = do_shmget(ns, h->perms.key, h->shm_segsz, shmflag, h->perms.id);
-	ckpt_debug("shm: do_shmget ret %d\n", ret);
+	ckpt_debug(ctx, "shm: do_shmget ret %d\n", ret);
 	if (ret < 0)
 		goto out;
 
@@ -266,7 +263,7 @@ int restore_ipc_shm(struct ckpt_ctx *ctx, struct ipc_namespace *ns)
  mutex:
 	fput(file);
 	if (ret < 0) {
-		ckpt_debug("shm: need to remove (%d)\n", ret);
+		ckpt_err(ctx, "shm: need to remove (%d)\n", ret);
 		do_shm_rmid(ns, perms);
 	} else
 		ipc_unlock(perms);
kernel/cred.c +1 -1
index 62d28a4..850c9c6 100644
@@ -724,7 +724,7 @@ static int do_checkpoint_cred(struct ckpt_ctx *ctx, struct cred *cred)
 	if (!h)
 		return -ENOMEM;
 
-	ckpt_debug("cred uid %d fsuid %d gid %d\n", cred->uid, cred->fsuid,
+	ckpt_debug(ctx, "cred uid %d fsuid %d gid %d\n", cred->uid, cred->fsuid,
 			cred->gid);
 	h->uid = cred->uid;
 	h->suid = cred->suid;
lib/Kconfig.debug +1 -3
index e1ae6e6..73698ee 100644
@@ -1011,9 +1011,7 @@ config CHECKPOINT_DEBUG
 	depends on CHECKPOINT
 	default y
 	help
-	  This options turns on the debugging output of checkpoint/restart.
-	  The level of verbosity is controlled by 'ckpt_debug_level' and can
-	  be set at boot time with "ckpt_debug=" option.
+	  This options turns on extra debugging output of checkpoint/restart.
 
 	  Turning this option off will reduce the size of the c/r code. If
 	  turned on, it is unlikely to incur visible overhead if the debug
mm/filemap.c +1 -1
index eb7653d..ff8571b 100644
@@ -1730,7 +1730,7 @@ int filemap_restore(struct ckpt_ctx *ctx,
 		ret = private_vma_restore(ctx, mm, file, h);
 	} else {
 		/* shared mapped file */
-		addr = generic_vma_restore(mm, file, h);
+		addr = generic_vma_restore(ctx, mm, file, h);
 		ret = (IS_ERR((void *) addr) ? PTR_ERR((void *) addr) : 0);
 	}
 	return ret;
mm/shmem.c +1 -1
index 2cfff8d..b5954de 100644
@@ -2449,7 +2449,7 @@ int shmem_restore(struct ckpt_ctx *ctx,
 		get_file(file);
 	}
 
-	addr = generic_vma_restore(mm, file, h);
+	addr = generic_vma_restore(ctx, mm, file, h);
 	if (IS_ERR((void *) addr))
 		return PTR_ERR((void *) addr);
 
net/checkpoint.c +23 -23

156 lines not on this page · raw message

net/ipv4/checkpoint.c +12 -14
index 9cbbf5e..b0fda64 100644
@@ -71,7 +71,7 @@ static int inet_read_buffer(struct ckpt_ctx *ctx, struct sk_buff_head *queue)
 		ret = len;
 		goto out;
 	} else if (len > SKB_MAX_ALLOC) {
-		ckpt_debug("Socket buffer too big (%i > %lu)",
+		ckpt_err(ctx, "Socket buffer too big (%i > %lu)",
 			   len, SKB_MAX_ALLOC);
 		ret = -ENOSPC;
 		goto out;
@@ -111,12 +111,12 @@ static int inet_read_buffers(struct ckpt_ctx *ctx, struct sk_buff_head *queue)
 
 	for (i = 0; i < h->skb_count; i++) {
 		ret = inet_read_buffer(ctx, queue);
-		ckpt_debug("read inet buffer %i: %i", i, ret);
+		ckpt_debug(ctx, "read inet buffer %i: %i", i, ret);
 		if (ret < 0)
 			goto out;
 
 		if (ret > h->total_bytes) {
-			ckpt_debug("Buffers exceeded claim");
+			ckpt_err(ctx, "Buffers exceeded claim");
 			ret = -EINVAL;
 			goto out;
 		}
@@ -139,12 +139,12 @@ static int inet_deferred_restore_buffers(void *data)
 	int ret;
 
 	ret = inet_read_buffers(ctx, &sk->sk_receive_queue);
-	ckpt_debug("(R) inet_read_buffers: %i\n", ret);
+	ckpt_debug(ctx, "(R) inet_read_buffers: %i\n", ret);
 	if (ret < 0)
 		return ret;
 
 	ret = inet_read_buffers(ctx, &sk->sk_write_queue);
-	ckpt_debug("(W) inet_read_buffers: %i\n", ret);
+	ckpt_debug(ctx, "(W) inet_read_buffers: %i\n", ret);
 
 	return ret;
 }
@@ -162,15 +162,11 @@ static int inet_defer_restore_buffers(struct ckpt_ctx *ctx, struct sock *sk)
 
 static int inet_precheck(struct socket *sock, struct ckpt_hdr_socket_inet *in)
 {
-	if (in->laddr_len > sizeof(struct sockaddr_in)) {
-		ckpt_debug("laddr_len is too big\n");
+	if (in->laddr_len > sizeof(struct sockaddr_in))
 		return -EINVAL;
-	}
 
-	if (in->raddr_len > sizeof(struct sockaddr_in)) {
-		ckpt_debug("raddr_len is too big\n");
+	if (in->raddr_len > sizeof(struct sockaddr_in))
 		return -EINVAL;
-	}
 
 	return 0;
 }
@@ -187,8 +183,10 @@ int inet_restore(struct ckpt_ctx *ctx,
 		return PTR_ERR(in);
 
 	ret = inet_precheck(sock, in);
-	if (ret < 0)
+	if (ret < 0) {
+		ckpt_err(ctx, "laddr_len or raddr_len is too big\n");
 		goto out;
+	}
 
 	/* Listening sockets and those that are closed but have a local
 	 * address need to call bind()
@@ -200,13 +198,13 @@ int inet_restore(struct ckpt_ctx *ctx,
 		ret = sock->ops->bind(sock,
 				      (struct sockaddr *)&in->laddr,
 				      in->laddr_len);
-		ckpt_debug("inet bind: %i\n", ret);
+		ckpt_debug(ctx, "inet bind: %i\n", ret);
 		if (ret < 0)
 			goto out;
 
 		if (h->sock.state == TCP_LISTEN) {
 			ret = sock->ops->listen(sock, h->sock.backlog);
-			ckpt_debug("inet listen: %i\n", ret);
+			ckpt_debug(ctx, "inet listen: %i\n", ret);
 			if (ret < 0)
 				goto out;
 		}
net/unix/checkpoint.c +35 -30

228 lines not on this page · raw message

Signature · 1 line
1.6.1

A message that is not in the archive (sent off-list or not yet received): 20091021210507.GA2098-r/[email protected]

#2 lore raw

PATCH 1/1 Allow for logfile for kernel debug messages (v2)

If unspecified, -1 will be sent for logfd to the kernel, and there
will be no debug log. If specified, then checkpoint and restart
debug msgs will be sent to the logfile.

Logfile is specified using -l LOGFILE or --logfile=LOGFILE, i.e.

checkpoint $pid -o ckpt.out -l ckpt.debug
restart -l rstr.debug -i ckpt.out

Changelog:

	oct 21: take a --logall flag
---
 checkpoint.c |   34 ++++++++++++++++++++++++++++++----
 restart.c    |   47 +++++++++++++++++++++++++++++++++++++++++------
 2 files changed, 71 insertions(+), 10 deletions(-)
checkpoint.c +30 -4
index c116daf..553132c 100644
@@ -32,6 +32,8 @@ static char usage_str[] =
 "\tOptions:\n"
 "  -h,--help             print this help message\n"
 "  -o,--output=FILE      write data to FILE instead of standard output\n"
+"  -l,--logfile=FILE     write kernel debug data to FILE (default=nowhere)\n"
+"  -a,--logall           have kernel output all debug data, not just errors\n"
 "  -c,--container        require the PID is a container-init\n"
 "  -v,--verbose          verbose output\n"
 "";
@@ -40,11 +42,13 @@ struct args {
 	char *output;
 	int container;
 	int verbose;
+	int logall;
+	char *logfile;
 };
 
-inline static int checkpoint(pid_t pid, int fd, unsigned long flags)
+inline static int checkpoint(pid_t pid, int fd, unsigned long flags, int logfd)
 {
-	return syscall(__NR_checkpoint, pid, fd, flags);
+	return syscall(__NR_checkpoint, pid, fd, flags, logfd);
 }
 
 static void usage(char *str)
@@ -59,10 +63,12 @@ static void parse_args(struct args *args, int argc, char *argv[])
 		{ "help",	no_argument,		NULL, 'h' },
 		{ "output",	required_argument,	NULL, 'o' },
 		{ "container",	no_argument,		NULL, 'c' },
+		{ "logfile",	required_argument,	NULL, 'l' },
+		{ "logall",	required_argument,	NULL, 'a' },
 		{ "verbose",	no_argument,		NULL, 'v' },
 		{ NULL,		0,			NULL, 0 }
 	};
-	static char optc[] = "hvco:";
+	static char optc[] = "ahvco:l:";
 
 	while (1) {
 		int c = getopt_long(argc, argv, optc, opts, NULL);
@@ -73,12 +79,18 @@ static void parse_args(struct args *args, int argc, char *argv[])
 			exit(1);
 		case 'h':
 			usage(usage_str);
+		case 'a':
+			args->logall = 1;
+			break;
 		case 'o':
 			args->output = optarg;
 			break;
 		case 'c':
 			args->container = 1;
 			break;
+		case 'l':
+			args->logfile = optarg;
+			break;
 		case 'v':
 			args->verbose = 1;
 			break;
@@ -94,6 +106,7 @@ int main(int argc, char *argv[])
 	unsigned long flags = 0;
 	pid_t pid;
 	int ret;
+	int logfd;
 
 	memset(&args, 0, sizeof(args));
 	parse_args(&args, argc, argv);
@@ -125,8 +138,21 @@ int main(int argc, char *argv[])
 		if (ret != STDOUT_FILENO)
 			close(ret);
 	}
+	if (args.logfile) {
+		logfd = open(args.logfile, O_RDWR | O_CREAT, 0600);
+		if (logfd < 0) {
+			perror("open logfile");
+			exit(1);
+		}
+	}
+
+	if (args.logall) {
+		if (!args.logfile)
+			printf("Warning: -a specified but no logfile\n");
+		flags |= CHECKPOINT_LOG_ALL;
+	}
 
-	ret = checkpoint(pid, STDOUT_FILENO, flags);
+	ret = checkpoint(pid, STDOUT_FILENO, flags, logfd);
 
 	if (ret < 0) {
 		perror("checkpoint");
restart.c +41 -6

125 lines not on this page · raw message

Signature · 1 line
1.6.1.1

A message that is not in the archive (sent off-list or not yet received): 20091021210533.GA2165-r/[email protected]

#4 lore raw

Re: [PATCH user-cr] Allow for logfile for kernel debug messages (v2)

Quoted 3 lines · Serge E. Hallyn

If unspecified, -1 will be sent for logfd to the kernel, and there
will be no debug log. If specified, then checkpoint and restart
debug msgs will be sent to the logfile.

The new interface will cover error reporting, so when run without '-l' both 'checkpoint' and 'restart' (unless asked to run extra silently) need to provide a pipe to the syscall, and if an error occurs, display pull the error reason from the pipe and print it.

Quoted 20 lines

Logfile is specified using -l LOGFILE or --logfile=LOGFILE, i.e.

checkpoint $pid -o ckpt.out -l ckpt.debug
restart -l rstr.debug -i ckpt.out

Changelog:

	oct 21: take a --logall flag
---
 checkpoint.c |   34 ++++++++++++++++++++++++++++++----
 restart.c    |   47 +++++++++++++++++++++++++++++++++++++++++------
 2 files changed, 71 insertions(+), 10 deletions(-)
checkpoint.c +0 -0
index c116daf..553132c 100644

checkpoint.c static char usage_str[] = · line 35

Quoted 4 lines
checkpoint.c +1 -0
@@ -32,6 +32,8 @@ static char usage_str[] =
 "\tOptions:\n"
 "  -h,--help             print this help message\n"
 "  -o,--output=FILE      write data to FILE instead of standard output\n"
+"  -l,--logfile=FILE     write kernel debug data to FILE (default=nowhere)\n"

Can the user ask to append the data to a file ?

Also, I'm thinking of adding --output-fd=FD (and then --logfile-fd=FD) to allow a user to first create suitable fds and then exec the program (that will allow to easily redirect input/output without adding endless options).

checkpoint.c static char usage_str[] = · line 36

Quoted 1 line
checkpoint.c +1 -0
+"  -a,--logall           have kernel output all debug data, not just errors\n"

Maybe use '-d'/'-D', or some --debug-log instead ?

Quoted 61 lines
checkpoint.c +14 -3
 "  -c,--container        require the PID is a container-init\n"
 "  -v,--verbose          verbose output\n"
 "";
@@ -40,11 +42,13 @@ struct args {
 	char *output;
 	int container;
 	int verbose;
+	int logall;
+	char *logfile;
 };
 
-inline static int checkpoint(pid_t pid, int fd, unsigned long flags)
+inline static int checkpoint(pid_t pid, int fd, unsigned long flags, int logfd)
 {
-	return syscall(__NR_checkpoint, pid, fd, flags);
+	return syscall(__NR_checkpoint, pid, fd, flags, logfd);
 }
 
 static void usage(char *str)
@@ -59,10 +63,12 @@ static void parse_args(struct args *args, int argc, char *argv[])
 		{ "help",	no_argument,		NULL, 'h' },
 		{ "output",	required_argument,	NULL, 'o' },
 		{ "container",	no_argument,		NULL, 'c' },
+		{ "logfile",	required_argument,	NULL, 'l' },
+		{ "logall",	required_argument,	NULL, 'a' },
 		{ "verbose",	no_argument,		NULL, 'v' },
 		{ NULL,		0,			NULL, 0 }
 	};
-	static char optc[] = "hvco:";
+	static char optc[] = "ahvco:l:";
 
 	while (1) {
 		int c = getopt_long(argc, argv, optc, opts, NULL);
@@ -73,12 +79,18 @@ static void parse_args(struct args *args, int argc, char *argv[])
 			exit(1);
 		case 'h':
 			usage(usage_str);
+		case 'a':
+			args->logall = 1;
+			break;
 		case 'o':
 			args->output = optarg;
 			break;
 		case 'c':
 			args->container = 1;
 			break;
+		case 'l':
+			args->logfile = optarg;
+			break;
 		case 'v':
 			args->verbose = 1;
 			break;
@@ -94,6 +106,7 @@ int main(int argc, char *argv[])
 	unsigned long flags = 0;
 	pid_t pid;
 	int ret;
+	int logfd;
 
 	memset(&args, 0, sizeof(args));
 	parse_args(&args, argc, argv);

checkpoint.c int main(int argc, char *argv[]) · line 142

Quoted 5 lines
checkpoint.c +2 -0
@@ -125,8 +138,21 @@ int main(int argc, char *argv[])
 		if (ret != STDOUT_FILENO)
 			close(ret);
 	}
+	if (args.logfile) {
+		logfd = open(args.logfile, O_RDWR | O_CREAT, 0600);

What if the file exists -- always overwrite ?

checkpoint.c int main(int argc, char *argv[]) · line 147

Quoted 5 lines
checkpoint.c +5 -0
+		if (logfd < 0) {
+			perror("open logfile");
+			exit(1);
+		}
+	}

[...]

The comments above also apply to the 'restart' part.

Thanks,

Oren.

A message that is not in the archive (sent off-list or not yet received): [email protected]

#6 lore raw

Re: [PATCH user-cr] Allow for logfile for kernel debug messages (v2)

Quoted 7 lines · Oren Laadan
Quoted 3 lines · Serge E. Hallyn

If unspecified, -1 will be sent for logfd to the kernel, and there
will be no debug log. If specified, then checkpoint and restart
debug msgs will be sent to the logfile.

The new interface will cover error reporting, so when run without '-l'

Not sure what you mean by 'the new interface will cover error reporting'.

Quoted 3 lines

both 'checkpoint' and 'restart' (unless asked to run extra silently) need to provide a pipe to the syscall, and if an error occurs, display pull the error reason from the pipe and print it.

Sounds like a useful feature, but to be clear note that what is now ckpt_err() output from the kernel was debug output before, so compared to without this patchset, the user is not losing any information.

In fact what you're saying sounds like even more justification for changing some of the

	ret = abc();
	ckpt_debug("...", ret);
	if (!ret)
		ret = cdef();
	ckpt_debug("...", ret);

type of flow into one where ckpt_err() is used and only in the case of a definite error. Yes?

-serge

A message that is not in the archive (sent off-list or not yet received): [email protected]

#8 lore raw

Re: [PATCH user-cr] Allow for logfile for kernel debug messages (v2)

Quoted 8 lines · Serge E. Hallyn
Quoted 5 lines · Oren Laadan
Quoted 3 lines · Serge E. Hallyn

If unspecified, -1 will be sent for logfd to the kernel, and there
will be no debug log. If specified, then checkpoint and restart
debug msgs will be sent to the logfile.

The new interface will cover error reporting, so when run without '-l'

Not sure what you mean by 'the new interface will cover error reporting'.

I mean that using an logging fd rids the need to write an error record to the checkpoint image. So I think we may retire ckpt_write_err() in favor of the new interface.

The downside (if any) is that the error message is cannot be recovered from the partial image file (so what ?).

And, unlike now, it's a way to report the reason for a restart failure back to the caller.

I'd like both 'checkpoint' and 'restart' to report the reason for a failure to the caller (either by default, or with a new switch).

Quoted 8 lines
Quoted 4 lines

both 'checkpoint' and 'restart' (unless asked to run extra silently) need to provide a pipe to the syscall, and if an error occurs, display pull the error reason from the pipe and print it.

Sounds like a useful feature, but to be clear note that what is now ckpt_err() output from the kernel was debug output before, so compared to without this patchset, the user is not losing any information.

True for checkpoint. But the motivation for the new interface (besides debugging), is to have the same error reporting for restart, too.

Quoted 4 lines

In fact what you're saying sounds like even more justification for changing some of the

Quoted 8 lines
	ret = abc();
	ckpt_debug("...", ret);
	if (!ret)
		ret = cdef();
	ckpt_debug("...", ret);

type of flow into one where ckpt_err() is used and only in the case of a definite error. Yes?

Hmm... I'm not sure.

I think (...) I'm suggesting two classes of output:
- ckpt_error() to report an error to the user
- ckpt_debug() to report debugging info for developers

The value of a @ret is interesting for error reporting only when it is negative; but for debugging it may be interesting even if an error did not occur.

Also, I expect more places where we want to see @ret for debugging. So @ret may be negative, but ckpt_error() will be called later (e.g. by our caller).

Oren.

A message that is not in the archive (sent off-list or not yet received): [email protected]

#10 lore raw

Re: [PATCH user-cr] Allow for logfile for kernel debug messages (v2)

Quoted 8 lines · Oren Laadan
Quoted 5 lines · Serge E. Hallyn
Quoted 4 lines · Oren Laadan
Quoted 3 lines · Serge E. Hallyn

If unspecified, -1 will be sent for logfd to the kernel, and there
will be no debug log. If specified, then checkpoint and restart
debug msgs will be sent to the logfile.

Quoted 7 lines
Quoted 3 lines
Quoted 1 line

The new interface will cover error reporting, so when run without '-l'

Not sure what you mean by 'the new interface will cover error reporting'.

I mean that using an logging fd rids the need to write an error record to the checkpoint image. So I think we may retire ckpt_write_err() in favor of the new interface.

Having the error in the image is incredibly useful. Not only does it tell you an error message but it establishes plenty of useful context -- the preceding portions of the checkpoint image. Removing it seems like it would be a big mistake.

Quoted 2 lines

The downside (if any) is that the error message is cannot be recovered from the partial image file (so what ?).

Because it's easy. The easier we make the interface to use the better. Otherwise we'll get people trying to piece together what happened from two separate streams -- the checkpoint image and the log -- and doing it poorly. Better to keep them intertwined in the case of checkpoint.

Cheers,
-Matt Helsley

#11 lore raw

Re: [PATCH user-cr] Allow for logfile for kernel debug messages (v2)

In reply to a message not in the archive
Quoted 10 lines · Oren Laadan
Quoted 3 lines · Serge E. Hallyn

If unspecified, -1 will be sent for logfd to the kernel, and there
will be no debug log. If specified, then checkpoint and restart
debug msgs will be sent to the logfile.

The new interface will cover error reporting, so when run without '-l' both 'checkpoint' and 'restart' (unless asked to run extra silently) need to provide a pipe to the syscall, and if an error occurs, display pull the error reason from the pipe and print it.

Of course if more than a pipe buf's worth of error data needs to be transferred then that scheme won't work very cleanly -- checkpoint/restart would always be a multi-task operation. (I just ran into this issue with self-checkpoint.)

Quoted 28 lines
Quoted 21 lines

Logfile is specified using -l LOGFILE or --logfile=LOGFILE, i.e.

checkpoint $pid -o ckpt.out -l ckpt.debug
restart -l rstr.debug -i ckpt.out

Changelog:

	oct 21: take a --logall flag
---
 checkpoint.c |   34 ++++++++++++++++++++++++++++++----
 restart.c    |   47 +++++++++++++++++++++++++++++++++++++++++------
 2 files changed, 71 insertions(+), 10 deletions(-)
checkpoint.c +0 -0
index c116daf..553132c 100644

checkpoint.c static char usage_str[] = · line 35

Quoted 4 lines
checkpoint.c +1 -0
@@ -32,6 +32,8 @@ static char usage_str[] =
 "\tOptions:\n"
 "  -h,--help             print this help message\n"
 "  -o,--output=FILE      write data to FILE instead of standard output\n"
+"  -l,--logfile=FILE     write kernel debug data to FILE (default=nowhere)\n"

Can the user ask to append the data to a file ?

Quoted 4 lines

Also, I'm thinking of adding --output-fd=FD (and then --logfile-fd=FD) to allow a user to first create suitable fds and then exec the program (that will allow to easily redirect input/output without adding endless options).

I like the output-fd idea. It means you don't need to be able to ask to append -- it's implicit in the file position of the passed file descriptor.

Cheers,
-Matt Helsley

A message that is not in the archive (sent off-list or not yet received): 20091022054853.GC7757-52DBMbEzqgQ/wnmkkaCWp/[email protected]

#13 lore raw

Re: [PATCH user-cr] Allow for logfile for kernel debug messages (v2)

Quoted 10 lines · Matt Helsley
Quoted 8 lines · Oren Laadan
Quoted 3 lines · Serge E. Hallyn

If unspecified, -1 will be sent for logfd to the kernel, and there
will be no debug log. If specified, then checkpoint and restart
debug msgs will be sent to the logfile.

The new interface will cover error reporting, so when run without '-l' both 'checkpoint' and 'restart' (unless asked to run extra silently) need to provide a pipe to the syscall, and if an error occurs, display pull the error reason from the pipe and print it.

Quoted 4 lines

Of course if more than a pipe buf's worth of error data needs to be transferred then that scheme won't work very cleanly -- checkpoint/restart would always be a multi-task operation. (I just ran into this issue with self-checkpoint.)

Of course. IIRC I commented at linux plumbers that error messages should (as in must) fit there, as opposed to log/debug messages.

Oren.

#14 lore raw
In reply to a message not in the archive
Quoted 7 lines · Serge E. Hallyn

Until now, debug data was sent to syslog. That's not really right.

This patch sends ckpt_debug output to a logfile provided by the caller. If no logfile is provided, then no debug output is needed. So the user can pass in -1 for the logfd to say so.

I suggest to keep an option to write to the console/syslog too. Otherwise we may lose important debug info if a nasty crash occurs ...

Quoted 5 lines

Note that this does not address the potential (inevitable?) lockup of writing out a debug msg while checkpointing the debug file. In practice so far it seems to work rather well. (with quite a bit of testing)

I believe the only concern here is that our debug code should not write any debug info while the respective inode is locked.

Quoted 9 lines

This also means that we have to be more careful than we have been about not writing out sensitive data.

This is pure RFC, not meant to be pretty.

The split into ckpt_debug and ckpt_err (see changelog) suggests that we should rearrange (and be more consistent about) how and when we print out debug info. Left as an exercise for later.

I hate homework...

Besides, I think we need to address it now. This patch is pretty intrusive and will be painful when I fold to ckpt-v19. I do not want to go through the process twice.

It's definitely time to come up with guidelines to when/where/how to add debugging output, and when/where/how to add error output.

In the 'how' section, besides avoiding leaking sensitive data, I'd like to come up with a canonical format that will be easy to read and to parse automatically (improve over ckpt_write_err).

Hmm... ckpt_write_err() should change too -- be written to the log instead.

Quoted 4 lines

Changelog:
Oct 21: split ckpt_debug into ckpt_debug and ckpt_err.
Git rid of the split by memory debug info etc.

The split is useful to control the amount of log.

Quoted 5 lines

Since userspace actively asks for debug info, I also made it not depend on CONFIG_CHECKPOINT_DEBUG. We may want to put it back again to limit kernel size, but for now it's a distraction, and I'm not convinced it makes sense

Then add CONFIG_CHECKPOINT_LOGGING ? (automatically implied by CONFIG_CHECKPOINT_DEBUG)

Quoted 22 lines
---
 arch/s390/kernel/compat_wrapper.S |    2 +
 arch/x86/mm/checkpoint.c          |   11 ++---
 checkpoint/checkpoint.c           |   22 ++++----
 checkpoint/files.c                |   29 +++++------
 checkpoint/memory.c               |   43 ++++++++-------
 checkpoint/namespace.c            |    3 -
 checkpoint/objhash.c              |   33 +++++++------
 checkpoint/process.c              |   85 +++++++++++++++----------------
 checkpoint/restart.c              |  101 +++++++++++++++++--------------------
 checkpoint/signal.c               |    5 +--
 checkpoint/sys.c                  |   94 ++++++++++++++++++++++------------
 drivers/char/tty_io.c             |   22 ++++----
 include/linux/checkpoint.h        |   85 ++++++++++++++++---------------
 include/linux/checkpoint_types.h  |    5 +-
 include/linux/syscalls.h          |    5 +-
 ipc/checkpoint.c                  |   13 ++---
 ipc/checkpoint_msg.c              |   13 ++---
 ipc/checkpoint_sem.c              |   13 ++---
 ipc/checkpoint_shm.c              |   15 ++---
Quoted 8 lines
 kernel/cred.c                     |    2 +-
 lib/Kconfig.debug                 |    4 +-
 mm/filemap.c                      |    2 +-
 mm/shmem.c                        |    2 +-
 net/checkpoint.c                  |   46 ++++++++--------
 net/ipv4/checkpoint.c             |   26 ++++-----
 net/unix/checkpoint.c             |   65 +++++++++++++-----------
 26 files changed, 380 insertions(+), 366 deletions(-)

Uhhh... when this matures from RFC to patch-for-inclusion, make sure to split it nicely for me ... please.

Oren.

A message that is not in the archive (sent off-list or not yet received): [email protected]

#16 lore raw
Quoted 6 lines · Oren Laadan
Quoted 3 lines · Serge E. Hallyn

Until now, debug data was sent to syslog. That's not really right.

Quoted 8 lines
Quoted 4 lines

This patch sends ckpt_debug output to a logfile provided by the caller. If no logfile is provided, then no debug output is needed. So the user can pass in -1 for the logfd to say so.

I suggest to keep an option to write to the console/syslog too. Otherwise we may lose important debug info if a nasty crash occurs ...

Ok, that should be simple enough to tack on once the rest is settled - just have ckpt_log() sent fmt+##args to both do_ckpt_user_debug() (to write to user-provided file) and a ckpt_syslog() which is a noop if !CONFIG_CHECKPOINT_DEBUG.

Quoted 7 lines
Quoted 4 lines

Note that this does not address the potential (inevitable?) lockup of writing out a debug msg while checkpointing the debug file. In practice so far it seems to work rather well. (with quite a bit of testing)

I believe the only concern here is that our debug code should not write any debug info while the respective inode is locked.

BTW it occurs to me that self-restart with a logfd must be kinda hosed early on :)

Quoted 9 lines
Quoted 8 lines

This also means that we have to be more careful than we have been about not writing out sensitive data.

This is pure RFC, not meant to be pretty.

The split into ckpt_debug and ckpt_err (see changelog) suggests that we should rearrange (and be more consistent about) how and when we print out debug info. Left as an exercise for later.

Quoted 5 lines

I hate homework...

Besides, I think we need to address it now. This patch is pretty intrusive and will be painful when I fold to ckpt-v19. I do not want to go through the process twice.

Ok, why don't I take my best stab at this in my next patch.

Quoted 9 lines

It's definitely time to come up with guidelines to when/where/how to add debugging output, and when/where/how to add error output.

In the 'how' section, besides avoiding leaking sensitive data, I'd like to come up with a canonical format that will be easy to read and to parse automatically (improve over ckpt_write_err).

Hmm... ckpt_write_err() should change too -- be written to the log instead.

Let's not be hasty - maybe duplicated, but an error message at the end of the checkpoint file is still a nice sanity check for userspace if they happened to checkpoint without a logfile.

Quoted 5 lines
Quoted 3 lines

Changelog:
Oct 21: split ckpt_debug into ckpt_debug and ckpt_err.
Git rid of the split by memory debug info etc.

The split is useful to control the amount of log.

It's a stupid split! And I've never used it. Besides, when a log is for a single c/r, it's really not very big.

More practically, requiring userspace to pass over a flag consisting of CKPT_DBG_MEM|CKPT_DBG|FILE|CKPT_DBG|TASK, and handle corresponding usage flags, is not nice.

Quoted 8 lines
Quoted 5 lines

Since userspace actively asks for debug info, I also made it not depend on CONFIG_CHECKPOINT_DEBUG. We may want to put it back again to limit kernel size, but for now it's a distraction, and I'm not convinced it makes sense

Then add CONFIG_CHECKPOINT_LOGGING ? (automatically implied by CONFIG_CHECKPOINT_DEBUG)

Well... for some reason I can't decide... does that make sense?

Remember more config options means more ways for the code to
not compile. Before adding one, I'd prefer to compile an image with and without the ckpt_debugs (iow with the #defines under #ifdef 0) and see how much size it really adds. And in face right now CONFIG_CHECKPOINT_DEBUG only directs creation of the extra restart task debug info, which is only printed out when ctx->uflags & CKPT_DEBUG_ALL, so that config option could go away entirely.

Quoted 30 lines
Quoted 21 lines
---
 arch/s390/kernel/compat_wrapper.S |    2 +
 arch/x86/mm/checkpoint.c          |   11 ++---
 checkpoint/checkpoint.c           |   22 ++++----
 checkpoint/files.c                |   29 +++++------
 checkpoint/memory.c               |   43 ++++++++-------
 checkpoint/namespace.c            |    3 -
 checkpoint/objhash.c              |   33 +++++++------
 checkpoint/process.c              |   85 +++++++++++++++----------------
 checkpoint/restart.c              |  101 +++++++++++++++++--------------------
 checkpoint/signal.c               |    5 +--
 checkpoint/sys.c                  |   94 ++++++++++++++++++++++------------
 drivers/char/tty_io.c             |   22 ++++----
 include/linux/checkpoint.h        |   85 ++++++++++++++++---------------
 include/linux/checkpoint_types.h  |    5 +-
 include/linux/syscalls.h          |    5 +-
 ipc/checkpoint.c                  |   13 ++---
 ipc/checkpoint_msg.c              |   13 ++---
 ipc/checkpoint_sem.c              |   13 ++---
 ipc/checkpoint_shm.c              |   15 ++---
Quoted 8 lines
 kernel/cred.c                     |    2 +-
 lib/Kconfig.debug                 |    4 +-
 mm/filemap.c                      |    2 +-
 mm/shmem.c                        |    2 +-
 net/checkpoint.c                  |   46 ++++++++--------
 net/ipv4/checkpoint.c             |   26 ++++-----
 net/unix/checkpoint.c             |   65 +++++++++++++-----------
 26 files changed, 380 insertions(+), 366 deletions(-)
Quoted 2 lines

Uhhh... when this matures from RFC to patch-for-inclusion, make sure to split it nicely for me ... please.

I'm not sure how split-able it is, but i'll do my best.

-serge

A message that is not in the archive (sent off-list or not yet received): 20091021224922.GA5827-r/[email protected]

#18 lore raw
Quoted 23 lines · Serge E. Hallyn
Quoted 5 lines · Oren Laadan
Quoted 3 lines · Serge E. Hallyn

Until now, debug data was sent to syslog. That's not really right.

Quoted 7 lines
Quoted 4 lines

This patch sends ckpt_debug output to a logfile provided by the caller. If no logfile is provided, then no debug output is needed. So the user can pass in -1 for the logfd to say so.

I suggest to keep an option to write to the console/syslog too. Otherwise we may lose important debug info if a nasty crash occurs ...

Ok, that should be simple enough to tack on once the rest is settled - just have ckpt_log() sent fmt+##args to both do_ckpt_user_debug() (to write to user-provided file) and a ckpt_syslog() which is a noop if !CONFIG_CHECKPOINT_DEBUG.

Quoted 4 lines
Quoted 4 lines

Note that this does not address the potential (inevitable?) lockup of writing out a debug msg while checkpointing the debug file. In practice so far it seems to work rather well. (with quite a bit of testing)

Quoted 5 lines
Quoted 2 lines

I believe the only concern here is that our debug code should not write any debug info while the respective inode is locked.

BTW it occurs to me that self-restart with a logfd must be kinda hosed early on :)

Why would that be a problem ? I actually think it's useful for those doing self-restart: you open a file, the kernel takes a reference to it, then sys_restart() will eventually close that file descriptor - but kernel still keeps a reference - so debug data keeps flowing. When restart completes -- data is gone; If restart fails - user will have information in that file.

Quoted 24 lines
Quoted 6 lines
Quoted 6 lines

This also means that we have to be more careful than we have been about not writing out sensitive data.

This is pure RFC, not meant to be pretty.

Quoted 8 lines
Quoted 3 lines

The split into ckpt_debug and ckpt_err (see changelog) suggests that we should rearrange (and be more consistent about) how and when we print out debug info. Left as an exercise for later.

I hate homework...

Besides, I think we need to address it now. This patch is pretty intrusive and will be painful when I fold to ckpt-v19. I do not want to go through the process twice.

Ok, why don't I take my best stab at this in my next patch.

Quoted 7 lines

It's definitely time to come up with guidelines to when/where/how to add debugging output, and when/where/how to add error output.

In the 'how' section, besides avoiding leaking sensitive data, I'd like to come up with a canonical format that will be easy to read and to parse automatically (improve over ckpt_write_err).

Quoted 6 lines
Quoted 2 lines

Hmm... ckpt_write_err() should change too -- be written to the log instead.

Let's not be hasty - maybe duplicated, but an error message at the end of the checkpoint file is still a nice sanity check for userspace if they happened to checkpoint without a logfile.

Ok.

Quoted 8 lines
Quoted 5 lines
Quoted 4 lines

Changelog:
Oct 21: split ckpt_debug into ckpt_debug and ckpt_err.
Git rid of the split by memory debug info etc.

The split is useful to control the amount of log.

It's a stupid split! And I've never used it. Besides, when a log is for a single c/r, it's really not very big.

It may be stupid split!, yet it did prove very useful to me. Maybe it's because you never debugged the memory checkpoint page by page.

A typical scenario: you hit a bug -> you enable debugging -> the bug disappears -> you disable debugging -> you hit the bug ...

IOW, debugging output in big doses affects the execution in a way that makes heisen-bugs hide. Control over verbosity means you get better chances at reproducing the behavior and still have enough meaningful data.

Quoted 4 lines

More practically, requiring userspace to pass over a flag consisting of CKPT_DBG_MEM|CKPT_DBG|FILE|CKPT_DBG|TASK, and handle corresponding usage flags, is not nice.

I agree with you on about this. Maybe we want a better interface ?

Which brings me to this random thought: maybe we want to make the fourth argument of sys_{checkpoint,restart} a structure, to make it easier to extend it in the future without having to go throw a clone3-like hell...

Specifically, this structure could now be:

struct ckpt_args {
	int version;
	int logfd;
	int logmask;
};

(or use union checkpoint {} and union restart {} to tell between checkpoint- and restart-related args.

Quoted 48 lines
Quoted 8 lines
Quoted 6 lines

Since userspace actively asks for debug info, I also made it not depend on CONFIG_CHECKPOINT_DEBUG. We may want to put it back again to limit kernel size, but for now it's a distraction, and I'm not convinced it makes sense

Then add CONFIG_CHECKPOINT_LOGGING ? (automatically implied by CONFIG_CHECKPOINT_DEBUG)

Well... for some reason I can't decide... does that make sense?

Remember more config options means more ways for the code to
not compile. Before adding one, I'd prefer to compile an image with and without the ckpt_debugs (iow with the #defines under #ifdef 0) and see how much size it really adds. And in face right now CONFIG_CHECKPOINT_DEBUG only directs creation of the extra restart task debug info, which is only printed out when ctx->uflags & CKPT_DEBUG_ALL, so that config option could go away entirely.

Quoted 29 lines
Quoted 29 lines
---
 arch/s390/kernel/compat_wrapper.S |    2 +
 arch/x86/mm/checkpoint.c          |   11 ++---
 checkpoint/checkpoint.c           |   22 ++++----
 checkpoint/files.c                |   29 +++++------
 checkpoint/memory.c               |   43 ++++++++-------
 checkpoint/namespace.c            |    3 -
 checkpoint/objhash.c              |   33 +++++++------
 checkpoint/process.c              |   85 +++++++++++++++----------------
 checkpoint/restart.c              |  101 +++++++++++++++++--------------------
 checkpoint/signal.c               |    5 +--
 checkpoint/sys.c                  |   94 ++++++++++++++++++++++------------
 drivers/char/tty_io.c             |   22 ++++----
 include/linux/checkpoint.h        |   85 ++++++++++++++++---------------
 include/linux/checkpoint_types.h  |    5 +-
 include/linux/syscalls.h          |    5 +-
 ipc/checkpoint.c                  |   13 ++---
 ipc/checkpoint_msg.c              |   13 ++---
 ipc/checkpoint_sem.c              |   13 ++---
 ipc/checkpoint_shm.c              |   15 ++---
 kernel/cred.c                     |    2 +-
 lib/Kconfig.debug                 |    4 +-
 mm/filemap.c                      |    2 +-
 mm/shmem.c                        |    2 +-
 net/checkpoint.c                  |   46 ++++++++--------
 net/ipv4/checkpoint.c             |   26 ++++-----
 net/unix/checkpoint.c             |   65 +++++++++++++-----------
 26 files changed, 380 insertions(+), 366 deletions(-)
Quoted 4 lines
Quoted 2 lines

Uhhh... when this matures from RFC to patch-for-inclusion, make sure to split it nicely for me ... please.

I'm not sure how split-able it is, but i'll do my best.

One way it to decide that we change the name ckpt_debug() to, say, ckpt_log_debug(), then you introduce the new function in on patch, and in following patches convert file by file.

Or, you just split it to first change ckpt_debug(), and then one patch per file (or per subsystem). It's not bisect-able, but that's ok because it's not going as is to the kernel - I'll fold it anyway into ckpt-v19 clean patchset.

Oren.

A message that is not in the archive (sent off-list or not yet received): [email protected]

#20 lore raw
Quoted 9 lines · Oren Laadan
Quoted 2 lines

BTW it occurs to me that self-restart with a logfd must be kinda hosed early on :)

Why would that be a problem ? I actually think it's useful for those doing self-restart: you open a file, the kernel takes a reference to it, then sys_restart() will eventually close that file descriptor - but kernel still keeps a reference - so debug data keeps flowing. When restart completes -- data is gone; If restart fails - user will have information in that file.

Hmm, good point. No problem then.

...

Quoted 9 lines
Quoted 7 lines
Quoted 4 lines
Quoted 3 lines

Changelog:
Oct 21: split ckpt_debug into ckpt_debug and ckpt_err.
Git rid of the split by memory debug info etc.

The split is useful to control the amount of log.

It's a stupid split! And I've never used it. Besides, when a log is for a single c/r, it's really not very big.

It may be stupid split!, yet it did prove very useful to me.

Sorry, stupid isn't right. Clearly it made sense.

Quoted 10 lines

Maybe it's because you never debugged the memory checkpoint page by page.

A typical scenario: you hit a bug -> you enable debugging -> the bug disappears -> you disable debugging -> you hit the bug ...

IOW, debugging output in big doses affects the execution in a way that makes heisen-bugs hide. Control over verbosity means you get better chances at reproducing the behavior and still have enough meaningful data.

So I guess it should stay in there at least for syslog output. Then you could debug by not passing an fd for the logfile to sys_restart, and tweaking the syslog output.

Quoted 14 lines
Quoted 3 lines

More practically, requiring userspace to pass over a flag consisting of CKPT_DBG_MEM|CKPT_DBG|FILE|CKPT_DBG|TASK, and handle corresponding usage flags, is not nice.

I agree with you on about this. Maybe we want a better interface ?

Which brings me to this random thought: maybe we want to make the fourth argument of sys_{checkpoint,restart} a structure, to make it easier to extend it in the future without having to go throw a clone3-like hell...

Specifically, this structure could now be:

Quoted 8 lines
struct ckpt_args {
	int version;
	int logfd;
	int logmask;
};

(or use union checkpoint {} and union restart {} to tell between checkpoint- and restart-related args.

Well I don't like passing structs to the kernel actually (and don't like that in the clone3 patchset :), but can't think of anything better offhand. I'll think about it a bit more, but maybe this'll be the way to go - long as a very simple program can pass NULL to mean no debug.

-serge

A message that is not in the archive (sent off-list or not yet received): 20091022005157.GA11608-r/[email protected]

#22 lore raw
Quoted 1 line · Serge E. Hallyn

Quoting Oren Laadan ([email protected]):

<snip>

Quoted 11 lines
Quoted 11 lines
Quoted 3 lines

More practically, requiring userspace to pass over a flag consisting of CKPT_DBG_MEM|CKPT_DBG|FILE|CKPT_DBG|TASK, and handle corresponding usage flags, is not nice.

I agree with you on about this. Maybe we want a better interface ?

Which brings me to this random thought: maybe we want to make the fourth argument of sys_{checkpoint,restart} a structure, to make it easier to extend it in the future without having to go throw a clone3-like hell...

Adding new kernel interfaces is supposed to be somewhat hellish.

Quoted 9 lines
Quoted 9 lines

Specifically, this structure could now be:

struct ckpt_args {
	int version;
	int logfd;
	int logmask;
};
Quoted 4 lines
Quoted 2 lines

(or use union checkpoint {} and union restart {} to tell between checkpoint- and restart-related args.

Well I don't like passing structs to the kernel actually (and

Let's not do this. I agree that passing structs, when unnecessary, is gross. Especially if it gets used to extend the arguments passed via the syscall interface (new flag values I don't mind).

Cheers,
-Matt Helsley

A message that is not in the archive (sent off-list or not yet received): 20091022060400.GE7757-52DBMbEzqgQ/wnmkkaCWp/[email protected]

#24 lore raw
Quoted 26 lines · Matt Helsley
Quoted 1 line · Serge E. Hallyn

Quoting Oren Laadan ([email protected]):

<snip>

Quoted 10 lines
Quoted 10 lines
Quoted 3 lines

More practically, requiring userspace to pass over a flag consisting of CKPT_DBG_MEM|CKPT_DBG|FILE|CKPT_DBG|TASK, and handle corresponding usage flags, is not nice.

I agree with you on about this. Maybe we want a better interface ?

Which brings me to this random thought: maybe we want to make the fourth argument of sys_{checkpoint,restart} a structure, to make it easier to extend it in the future without having to go throw a clone3-like hell...

Adding new kernel interfaces is supposed to be somewhat hellish.

Quoted 8 lines
Quoted 8 lines

Specifically, this structure could now be:

struct ckpt_args {
	int version;
	int logfd;
	int logmask;
};
Quoted 7 lines
Quoted 3 lines
Quoted 2 lines

(or use union checkpoint {} and union restart {} to tell between checkpoint- and restart-related args.

Well I don't like passing structs to the kernel actually (and

Let's not do this. I agree that passing structs, when unnecessary, is gross. Especially if it gets used to extend the arguments passed via the syscall interface (new flag values I don't mind).

Ok, we already allow future extension by being strict about which flags are taken or not.

Then what do we do with logmask ? I prefer it to be a per-syscall
value as opposed to a system-wise setting.

Oren.

A message that is not in the archive (sent off-list or not yet received): [email protected]

#26 lore raw
Quoted 37 lines · Oren Laadan
Quoted 26 lines · Matt Helsley
Quoted 1 line · Serge E. Hallyn

Quoting Oren Laadan ([email protected]):

<snip>

Quoted 10 lines
Quoted 10 lines
Quoted 3 lines

More practically, requiring userspace to pass over a flag consisting of CKPT_DBG_MEM|CKPT_DBG|FILE|CKPT_DBG|TASK, and handle corresponding usage flags, is not nice.

I agree with you on about this. Maybe we want a better interface ?

Which brings me to this random thought: maybe we want to make the fourth argument of sys_{checkpoint,restart} a structure, to make it easier to extend it in the future without having to go throw a clone3-like hell...

Adding new kernel interfaces is supposed to be somewhat hellish.

Quoted 8 lines
Quoted 8 lines

Specifically, this structure could now be:

struct ckpt_args {
	int version;
	int logfd;
	int logmask;
};
Quoted 7 lines
Quoted 3 lines
Quoted 2 lines

(or use union checkpoint {} and union restart {} to tell between checkpoint- and restart-related args.

Well I don't like passing structs to the kernel actually (and

Let's not do this. I agree that passing structs, when unnecessary, is gross. Especially if it gets used to extend the arguments passed via the syscall interface (new flag values I don't mind).

Quoted 5 lines

Ok, we already allow future extension by being strict about which flags are taken or not.

Then what do we do with logmask ? I prefer it to be a per-syscall
value as opposed to a system-wise setting.

Getting ugly but...

if we were to use tracepoints, then we could (or the admin could) have the function which is loaded determine based on a task's cgroup what to print out.

I did say it was ugly...

-serge

#27 lore raw
In reply to a message not in the archive
Quoted 37 lines · Oren Laadan
Quoted 26 lines · Matt Helsley
Quoted 1 line · Serge E. Hallyn

Quoting Oren Laadan ([email protected]):

<snip>

Quoted 10 lines
Quoted 10 lines
Quoted 3 lines

More practically, requiring userspace to pass over a flag consisting of CKPT_DBG_MEM|CKPT_DBG|FILE|CKPT_DBG|TASK, and handle corresponding usage flags, is not nice.

I agree with you on about this. Maybe we want a better interface ?

Which brings me to this random thought: maybe we want to make the fourth argument of sys_{checkpoint,restart} a structure, to make it easier to extend it in the future without having to go throw a clone3-like hell...

Adding new kernel interfaces is supposed to be somewhat hellish.

Quoted 8 lines
Quoted 8 lines

Specifically, this structure could now be:

struct ckpt_args {
	int version;
	int logfd;
	int logmask;
};
Quoted 7 lines
Quoted 3 lines
Quoted 2 lines

(or use union checkpoint {} and union restart {} to tell between checkpoint- and restart-related args.

Well I don't like passing structs to the kernel actually (and

Let's not do this. I agree that passing structs, when unnecessary, is gross. Especially if it gets used to extend the arguments passed via the syscall interface (new flag values I don't mind).

Quoted 5 lines

Ok, we already allow future extension by being strict about which flags are taken or not.

Then what do we do with logmask ? I prefer it to be a per-syscall
value as opposed to a system-wise setting.

Ok well let's be honest with ourselves - we'd like to give end-users reasonable debug info to figure out common problems. But we will always have cases where we have to hand-instrument the kernel for our own advanced debugging. Cases where you must print out only a specific info to catch a race condition probably will fit into such a case. So I'd prefer to aim for giving the end-user just one or a few options - nothing, errors only, or all debugging info that we care to insert in everyday kernels (which hopefully isn't too much, but let's a user figure out approximately where the problem happened, i.e. recreating a socket, opening a file, etc). Otherwise too much debugging will (a) deter from the readability of the code
(b) bulk up the kernel and (c) make the api cumberson (too many flags to checkpoint/restart userspace programs, and passing structs to syscall).

In fact I'm wondering whether for the shipped c/r kernel we want to have only ckpt_error()s and make sure we record the location in the restart file where we errored out. The ckpt_write_err() info is already very helpful in tracking down checkpoint errors. Of course this becomes a pain whenever we introduce a subte bug and have to hand-instrument everything. And then I have to curse all the printks I have to add. But it's not reasonabe to have every other line of c/r code be a debug statement either.

-serge

A message that is not in the archive (sent off-list or not yet received): 20091026215238.GA10900-r/[email protected]

#29 lore raw
Quoted 39 lines · Serge E. Hallyn
Quoted 29 lines · Oren Laadan
Quoted 27 lines · Matt Helsley
Quoted 1 line · Serge E. Hallyn

Quoting Oren Laadan ([email protected]):

<snip>

Quoted 10 lines
Quoted 10 lines
Quoted 3 lines

More practically, requiring userspace to pass over a flag consisting of CKPT_DBG_MEM|CKPT_DBG|FILE|CKPT_DBG|TASK, and handle corresponding usage flags, is not nice.

I agree with you on about this. Maybe we want a better interface ?

Which brings me to this random thought: maybe we want to make the fourth argument of sys_{checkpoint,restart} a structure, to make it easier to extend it in the future without having to go throw a clone3-like hell...

Adding new kernel interfaces is supposed to be somewhat hellish.

Quoted 11 lines
Quoted 10 lines

Specifically, this structure could now be:

struct ckpt_args {
	int version;
	int logfd;
	int logmask;
};

(or use union checkpoint {} and union restart {} to tell between checkpoint- and restart-related args.

Well I don't like passing structs to the kernel actually (and

Quoted 8 lines
Quoted 3 lines

Let's not do this. I agree that passing structs, when unnecessary, is gross. Especially if it gets used to extend the arguments passed via the syscall interface (new flag values I don't mind).

Ok, we already allow future extension by being strict about which flags are taken or not.

Then what do we do with logmask ? I prefer it to be a per-syscall
value as opposed to a system-wise setting.

Quoted 10 lines

Ok well let's be honest with ourselves - we'd like to give end-users reasonable debug info to figure out common problems. But we will always have cases where we have to hand-instrument the kernel for our own advanced debugging. Cases where you must print out only a specific info to catch a race condition probably will fit into such a case. So I'd prefer to aim for giving the end-user just one or a few options - nothing, errors only, or all debugging info that we care to insert in everyday kernels (which hopefully isn't too much, but let's a user figure out approximately where the problem happened, i.e. recreating a socket, opening a file, etc). Otherwise

I'm ok with this nothing-error-all scheme.

Two questions are:

What's "reasonable debug info" ?

How does it differ than looking at the image (checkpoint/restart) at the specific file position and error message ?

Quoted 5 lines

too much debugging will (a) deter from the readability of the code
(b) bulk up the kernel and (c) make the api cumberson (too many flags to checkpoint/restart userspace programs, and passing structs to syscall).

Quoted 8 lines

In fact I'm wondering whether for the shipped c/r kernel we want to have only ckpt_error()s and make sure we record the location in the restart file where we errored out. The ckpt_write_err() info is already very helpful in tracking down checkpoint errors. Of course this becomes a pain whenever we introduce a subte bug and have to hand-instrument everything. And then I have to curse all the printks I have to add. But it's not reasonabe to have every other line of c/r code be a debug statement either.

So you suggest ckpt_error() and ckpt_debug(). Fair enough.

Yet I'm not willing to give up my existing (too noisy for the user) debug statements for a chance to curse at their removal.

So I suggest also _ckpt_debug(), only with CONFIG_CHECKPOINT_DEBUG. They are there for developers, they can be used by a user who is having an issue and works with a developer, and they prevent Serge from cursing unnecessarily :p

(or can change the naming: ckpt_error, ckpt_log, ckpt_debug, etc).

Oren.

#30 lore raw
In reply to a message not in the archive

Quoting Oren Laadan ([email protected]):
...

Quoted 6 lines
Quoted 3 lines

More practically, requiring userspace to pass over a flag consisting of CKPT_DBG_MEM|CKPT_DBG|FILE|CKPT_DBG|TASK, and handle corresponding usage flags, is not nice.

I agree with you on about this. Maybe we want a better interface ?

I'm looking at tracehooks right now. So the way it would work is:

1. Error messages using ckpt_error() are always compiled in, are sent to ctx->logfile if that exists, and are sent to syslog if CONFIG_CHECKPOINT_DEBUG (or some sysctl is set).

2. Debug messages could be tracehooks which can be enabled per subsystem as above - for mem, file, task, etc - using code we add under linux-cr/samples/. It would basically do:

	  ret = register_trace_ckpt_mem(ckpt_trace_mem, ckpt_logprobe);
	  ret = register_trace_ckpt_task(ckpt_trace_mem, ckpt_logprobe);

where ckpt_logprobe does the printing of info to ctx->logfile and syslog.

Or,

at first of course we can just let CONFIG_CHECKPOINT_DEBUG determine the printing of ckpt_debugs() as we do now.

I'm going to start slowly, first defining the ckpt_error() helpers and introducing/converting some callers.

-serge