From: ian <ian>
Date: Sat, 24 May 2008 18:29:40 +0000 (+0000)
Subject: controllability of debugging; debugging not to simulation log
X-Git-Url: http://www.chiark.greenend.org.uk/ucgi/~ijackson/git?a=commitdiff_plain;h=d1bdcfde65efbf4d200a868a3bf8c0f6348281cd;p=trains.git

controllability of debugging; debugging not to simulation log
---

diff --git a/hostside/.cvsignore b/hostside/.cvsignore
index fd3ef62..eb8ad25 100644
--- a/hostside/.cvsignore
+++ b/hostside/.cvsignore
@@ -3,6 +3,7 @@ hostside-old
 hostside
 safety
 t
+u
 t.*
 layoutinfo.h
 *.d
@@ -20,3 +21,5 @@ record-l.[ch]
 record-y.[ch]
 +persist*
 +*.log
+*+dflags.h
+*.new
diff --git a/hostside/Makefile b/hostside/Makefile
index aa99570..e31dca6 100644
--- a/hostside/Makefile
+++ b/hostside/Makefile
@@ -3,7 +3,8 @@
 TRAINS=		santafe shinkansen
 
 AUTOINCS=	auproto-pic.h layoutinfo.h selectors.h retransmit-table.h \
-		errorcodes.h stastate.h record-y.h record-l.h
+		errorcodes.h stastate.h record-y.h record-l.h \
+		realtime+dflags.h
 TARGETS=	hostside-old gui-plan-bot realtime \
 		$(addsuffix .speeds.ps, $(TRAINS)) \
 		$(addsuffix .speeds.record, $(TRAINS))
@@ -29,15 +30,17 @@ on-bessar:	$(TARGETS)
 %.on-bessar:	%
 		RSYNC_RSH=fsh rsync $^ $(BESSAR)
 
-REALTIME_CORE=	realtime.o startup.o safety.o trackloc.o		\
-		 speed.o actual.o retransmit.o persist.o resolve.o	\
-		 cmdinput.o commands.o obc.o eventhelp.o simulate.o	\
-		 record.o record-l.o record-y.o				\
-		 utils.o serialio.o parseutils.o auproto-pic.o		\
-		 nmra.o encode.o movpos.o  rtprio.o			\
-		 ../layout/ours.layout-data.o
+REALTIME_CORE=	realtime startup safety trackloc		\
+		 speed actual retransmit persist resolve	\
+		 cmdinput commands obc eventhelp simulate	\
+		 record record-l record-y			\
+		 utils serialio parseutils auproto-pic		\
+		 nmra encode movpos  rtprio			\
+		 ../layout/ours.layout-data
 
-realtime:	$(REALTIME_CORE)				\
+REALTIME_CORE_OBJS= $(addsuffix .o, $(REALTIME_CORE))
+
+realtime:	$(REALTIME_CORE_OBJS)				\
 		 __oop-read-copy.o -loop -lm
 		$(LINK)
 
@@ -62,6 +65,10 @@ layoutinfo.h:	../layout/ours.layout-data.c Makefile
 selectors.h retransmit-table.h errorcodes.h stastate.h: %: %.gen
 		(echo "/*autogenerated*/" && ./$<) $o
 
+realtime+dflags.h: debug-extractor $(addsuffix .c, $(REALTIME_CORE))
+		./$^ >$@.new
+		cmp $@ $@.new || mv -f $@.new $@
+
 safety:		safety.o utils.o trackloc.o ../layout/ours.layout-data.o
 		$(LINK)
 
diff --git a/hostside/commands.c b/hostside/commands.c
index a23d4c5..36386a0 100644
--- a/hostside/commands.c
+++ b/hostside/commands.c
@@ -30,9 +30,9 @@ struct ManualRetransmitNode {
 
 static void cmd_ppc(Train *tra, Segment *seg, void *pu, const char *message) {
   const CmdInfo *ci= pu;
-  oprintf(UPO,"ack %s SignallingPredictedProblem %s %s : %s\n",
-	  ci->name,
-	  tra->pname, seg ? seg->i->pname : "?", message);
+  ouprintf("ack %s SignallingPredictedProblem %s %s : %s\n",
+	   ci->name,
+	   tra->pname, seg ? seg->i->pname : "?", message);
 }
 
 #define MUSTECRPREDICT(requester) do{					\
@@ -316,19 +316,19 @@ void command_doline(ParseState *ps, CommandInput *cmdi_arg) {
   r= ps_word(ps);  assert(!r);
   current_cmd= some_lookup(ps,toplevel_cmds);
   if (!current_cmd) {
-    oprintf(UPO,"nack unknown-command\n");
+    ouprintf("nack unknown-command\n");
     return;
   }
-  oprintf(UPO, "executing %s\n",current_cmd->name);
+  ouprintf("executing %s\n",current_cmd->name);
   if (sta_state < Sta_Run && !(current_cmd->xarg & CIXF_ANYSTA)) {
-    oprintf(UPO,"ack %s InvalidState : layout not ready\n",current_cmd->name);
+    ouprintf("ack %s InvalidState : layout not ready\n",current_cmd->name);
     return;
   }
   r= current_cmd->fn(ps,current_cmd);
   switch (r) {
-  case 0:  oprintf(UPO, "ack %s ok\n", current_cmd->name);                    break;
-  case EC_BadCmd:                                                    break;
-  default: oprintf(UPO, "ack %s %s\n", current_cmd->name, errorcodelist[r]);  break;
+  case 0:  ouprintf("ack %s ok\n",current_cmd->name);                  break;
+  case EC_BadCmd:                                                      break;
+  default: ouprintf("ack %s %s\n",current_cmd->name,errorcodelist[r]); break;
   }
 }
 
diff --git a/hostside/common.h b/hostside/common.h
index e0cccd9..6e4e19e 100644
--- a/hostside/common.h
+++ b/hostside/common.h
@@ -126,7 +126,7 @@ void real_mgettimeofday(struct timeval *tv);
 void mrename(const char *old, const char *new);
 void mwaitpid(pid_t child, const char *what);
 
-void badusage(const char *why);
+void badusage(const char *why) __attribute__((noreturn));
 
 #define massert(x) ((x) ? (void)0 : diem())
 
@@ -153,5 +153,7 @@ void nmra_encodeforpic(const Nmra *packet, PicInsn *pi_out);
 #define ARRAY_SIZE(a) (sizeof((a))/sizeof(*(a)))
 #define ARRAY_END(a) ((a) + ARRAY_SIZE((a)))
 
+#define CTYPE(isfoobar,ch) (isfoobar((unsigned char)(ch)))
+
 
 #endif /*COMMON_H*/
diff --git a/hostside/daemons.h b/hostside/daemons.h
index daea235..655c42c 100644
--- a/hostside/daemons.h
+++ b/hostside/daemons.h
@@ -22,11 +22,12 @@ typedef void OutBufferError(OutBufferChain*, const char *e1, const char *e2
 			    /* on error: both e1 and e2 non-0. say `$e1: $e2'
 			     * on eof: both e1 and e2 =0. */);
 
+typedef void CopyCallBack(char *m, size_t l, void *u);
+
 struct OutBufferChain {
   /* set by user: */
   char *desc;
   int fd;
-  FILE *logcopy;
   int limit; /* 0 means obc_init will set a default */
   OutBufferError *error;
   /* set/used by obc_..., oprintf, etc., only */
@@ -39,6 +40,9 @@ void obc_init_core(OutBufferChain *ch); /* doesn't mess with fd */
 int obc_tryflush(OutBufferChain *ch);
  /* returns 0 for all flushed or errno, including particularly EWOULDBLOCK */
 
+void ovprintf_ccb(OutBufferChain *ch, CopyCallBack *ccb, void *ccbu,
+		   const char *fmt, va_list al)
+     __attribute__((format(printf,4,0)));
 void ovprintf(OutBufferChain *ch, const char *fmt, va_list al)
      __attribute__((format(printf,2,0)));
 void oprintf(OutBufferChain *ch, const char *msg, ...)
diff --git a/hostside/debug-extractor b/hostside/debug-extractor
new file mode 100755
index 0000000..607ca43
--- /dev/null
+++ b/hostside/debug-extractor
@@ -0,0 +1,87 @@
+#!/usr/bin/perl -w
+
+use strict qw(vars);
+
+print <<END
+/* autogenerated - do not edit */
+
+#ifndef DEBUG_FLAGS_H
+#define DEBUG_FLAGS_H
+
+typedef struct {
+  unsigned long active, nondefault;
+} DebugSelectorKindFlags;
+
+typedef struct {
+  const char *name;
+  unsigned long bit;
+} DebugSelectorKindInfo;
+
+typedef struct {
+  const char *name;
+  const DebugSelectorKindInfo *kinds;
+  unsigned long *dflags, *userset;
+  unsigned long defdflags;
+} DebugSelectorAreaInfo;
+
+END
+    or die $!;
+
+our (%count);
+our ($decls)='';
+our ($defs)='';
+
+our ($shift,$decl,$ma,$mar,$mk);
+
+while (<>) {
+    next unless m/\bDPRINTF1?\((\w+),(\w+),/;
+    $count{$1}{$2}++;
+}
+
+foreach $ma (sort keys %count) {
+    $mar= $count{$ma};
+    $decl= "unsigned long dflags_$ma";
+    $decls.= "extern $decl;\n";
+    our $ddf= "DEFDFLAGS_${ma}";
+    $defs .= ("\n".
+	      "#ifndef $ddf\n".
+	      "# define $ddf ~0UL\n".
+	      "#endif\n");
+    $defs .= "static const DebugSelectorKindInfo dsiks_${ma}[]= {\n";
+    $shift= 0;
+    foreach $mk (sort { $mar->{$a} <=> $mar->{$b} or $a cmp $b } keys %$mar) {
+	next unless length $mk;
+	our $db= "DBIT_${ma}_${mk}";
+	our $v= 1<<$shift;
+	$shift++;
+	$defs.= sprintf "  { %-20s %-25s },\n", "\"$mk\",", $db;
+	printf "#define %-30s %0#10x /* %3d */\n", $db, $v, $mar->{$mk};
+    }
+    $defs.= "  { 0 }\n".
+	"};\n";
+    $defs.= "$decl;\n";
+    $defs.= "static unsigned long dflags_userset_$ma;\n";
+}
+$defs.= <<END;
+static const DebugSelectorAreaInfo dsais[]= {
+#define DSAI(x) \\
+  { #x, dsiks_##x, &dflags_##x, &dflags_userset_##x, DEFDFLAGS_##x }
+END
+foreach $ma (sort keys %count) {
+    $defs.= "DSAI($ma),\n"
+}
+$defs.= "  { 0 }\n".
+    "#undef DSAI\n".
+	"};\n";
+
+print <<END
+
+$decls
+#endif /*DEBUG_FLAGS_H*/
+
+#ifdef DEBUG_FLAGS_H_DEFINE
+$defs
+#endif /*DEBUG_FLAGS_H_DEFINE*/
+
+END
+    or die $!;
diff --git a/hostside/movpos.c b/hostside/movpos.c
index 83d4bca..f02043e 100644
--- a/hostside/movpos.c
+++ b/hostside/movpos.c
@@ -73,16 +73,16 @@ const char *movpos_pname(Segment *move, MovPosComb poscomb) {
 
 static void ouposn_moving(Change *chg) {
   Segment *move= chg->move;
-  oprintf(UPO, "movpos %s position %s moving\n",
-	  move->i->pname, movpos_pname(move, chg->actual));
+  ouprintf("movpos %s position %s moving\n",
+	   move->i->pname, movpos_pname(move, chg->actual));
 }
 
 static void motion_done(Segment *move, MovPosComb actual) {
   move->moving= 0;
   move->motion= 0;
   move->movposcomb= actual;
-  oprintf(UPO, "movpos %s position %s stable\n",
-	  move->i->pname, movpos_pname(move, move->movposcomb));
+  ouprintf("movpos %s position %s stable\n",
+	   move->i->pname, movpos_pname(move, move->movposcomb));
 }
 
 static void ignore_all_abandon(Method *m) { }
@@ -250,17 +250,17 @@ static void fsq_mark_as_allocated(FsqReq *r) { /* AX->X */
 
 static ErrorCode fsq_check_plan(FsqMethod *m) {
   /* Checks whether we can meet the currently queued commitments */
-  int future, conf, resv, whichwhen;
+  int future, conf, resv, whichwhen, DP;
   FsqReq *whichr;
 
   conf=resv=0;
   future=0;
 
-  oprintf(DUPO("movpos/fsq") "%s   plan", m->m.pname);
+  DPRINTF1(movpos,fsq, "%s   plan", m->m.pname);
 
   /* If CDU is charged we can't do one right away */
   if (m->f.ready<0) {
-    oprintf(UPO, " +");
+    DPRINTF2(" +");
     future++;
   }
 
@@ -268,29 +268,27 @@ static ErrorCode fsq_check_plan(FsqMethod *m) {
     FsqReq *confr= conf < m->f.confirmed.n ? m->f.confirmed.l[conf] : 0;
     FsqReq *resvr= resv < m->f.reserved .n ? m->f.reserved .l[resv] : 0;
     if (!confr && !resvr) break;
-    oprintf(UPO," %d:",future);
+    DPRINTF2(" %d:",future);
     int confwhen= confr ? confr->deadline - m->f.cslot : INT_MAX;
     int resvwhen= resvr ? resvr->deadline              : INT_MAX;
     if (future && resvwhen < confwhen) {
-      WHICH(resv);
-      oprintf(UPO,"~");
+      WHICH(resv);  DPRINTF2("~");
     } else if (confr) {
       WHICH(conf);
     } else {
-      oprintf(UPO,"-");
-      future++;
+      future++;     DPRINTF2("-");
       continue;
     }
-    oprintf(UPO, "%s/%s[%d@t+%d]", whichr->h.move->i->pname,
+    DPRINTF2("%s/%s[%d@t+%d]", whichr->h.move->i->pname,
 	    movpos_pname(whichr->h.move, whichr->h.intent),
 	    whichr->n_motions, whichwhen);
     if (future > whichwhen) {
-      oprintf(UPO,"!...bad\n");
+      DPRINTF2("!...bad\n");
       return EC_MovFeatTooLate;
     }
     future += whichr->n_motions;
   }
-  oprintf(UPO," ok\n");
+  DPRINTF2(" ok\n");
   return 0;
 }
 
@@ -349,19 +347,19 @@ static ErrorCode fsq_confirm(Method *mm, Change *chg, Segment *move,
   FsqMethod *m= (void*)mm;
   FsqReq *r= (FsqReq*)chg;
   FsqSlotSigned reldeadline;
-  int allow_failure;
+  int allow_failure, DP;
   ErrorCode ec;
 
-  oprintf(DUPO("movpos/fsq") "%s confirm %s n=%d maxdelay=%dms",
-	  m->m.pname, move->i->pname, n_motions, maxdelay_ms);
+  DPRINTF1(movpos,fsq, "%s confirm %s n=%d maxdelay=%dms",
+	   m->m.pname, move->i->pname, n_motions, maxdelay_ms);
 
   assert(!r->motions[0].i); /* no confirming things already confirmed */
   if (r->deadline==FSQDN)
-    oprintf(UPO, " (alloc'd: %d)\n", r->n_motions);
+    DPRINTF2(" (alloc'd: %d)\n", r->n_motions);
   else
-    oprintf(UPO, " (res: %s/%s[%d@t+%d])\n",
-	    r->h.move->i->pname, movpos_pname(r->h.move, r->h.intent),
-	    r->n_motions, r->deadline);
+    DPRINTF2(" (res: %s/%s[%d@t+%d])\n",
+	     r->h.move->i->pname, movpos_pname(r->h.move, r->h.intent),
+	     r->n_motions, r->deadline);
 
   /* If the segment is moving, these motions are already based on the
    * actual physical position which is stored in the existing request.
@@ -380,7 +378,7 @@ static ErrorCode fsq_confirm(Method *mm, Change *chg, Segment *move,
     reldeadline= fsq_maxdelay_reldeadline(m, maxdelay_ms, n_motions);
   }
   allow_failure= reldeadline < (FsqSlotSigned)r->deadline;
-  oprintf(DUPO("movpos/fsq") "%s  reldeadline=[%d@t+%d] allow_failure=%d\n",
+  DPRINTF(movpos,fsq, "%s  reldeadline=[%d@t+%d] allow_failure=%d\n",
 	  m->m.pname, n_motions, reldeadline, allow_failure);
 
   /* state A or R */
@@ -389,7 +387,7 @@ static ErrorCode fsq_confirm(Method *mm, Change *chg, Segment *move,
   FsqReq *existing=
     move->moving ? (FsqReq*)move->motion : 0;   /* U or C */
   if (existing) {
-    oprintf(DUPO("movpos/fsq")
+    DPRINTF(movpos,fsq,
 	    "%s  existing %s n=%d deadline=t+%d\n",
 	    m->m.pname,
 	    existing->h.move->i->pname,
@@ -413,7 +411,7 @@ static ErrorCode fsq_confirm(Method *mm, Change *chg, Segment *move,
 
   /* state CA */
   ec= fsq_enqueue(m, &m->f.confirmed, r);
-  oprintf(DUPO("movpos/fsq") "%s  fsq_enqueue=%s\n", m->m.pname, ec2str(ec));
+  DPRINTF(movpos,fsq, "%s  fsq_enqueue=%s\n", m->m.pname, ec2str(ec));
   assert(allow_failure || !ec);
 
   if (existing) {                                  /* CA */
@@ -467,8 +465,8 @@ static void fsq_check_action(FsqMethod *m) {
     assert(mo->posn < mo->i->posns);
     m->f.ready= 0;
     m->f.move(m, mo->i, mo->posn);
-    oprintf(UPO, "movpos %s feat %s %d %s\n", r->h.move->i->pname,
-	    mo->i->pname, mo->posn, m->m.pname);
+    ouprintf("movpos %s feat %s %d %s\n", r->h.move->i->pname,
+	     mo->i->pname, mo->posn, m->m.pname);
     m->f.cslot++;
 
     MovPosComb above_weight= mo->i->weight * mo->i->posns;
@@ -689,17 +687,17 @@ static FsqMethod waggle= {
 /*========== dummy `nomove' kind ==========*/
 
 static Change *nomove_allocate(Method *m, int alloc_motions) {
-  oprintf(DUPO("movfeatkind-momove") "allocate %d\n",alloc_motions);
+  DPRINTF(movpos,nomove, "allocate %d\n",alloc_motions);
   return mmalloc(sizeof(Change));
 }
 static ErrorCode nomove_reserve(Method *m, Change *c, Segment *move, int ms) {
-  oprintf(DUPO("movfeatkind-nomove") "reserve\n");
+  DPRINTF(movpos,nomove, "reserve\n");
   return 0;
 }
 static void nomove_destroy(Method *m, Change *c) { free(c); }
 static ErrorCode nomove_confirm(Method *m, Change *c, Segment *move, int n,
 		       const Motion *motions, int ms) {
-  oprintf(DUPO("movfeatkind-nomove") "confirm\n");
+  DPRINTF(movpos,nomove, "confirm\n");
   nomove_destroy(m,c);
   return 0;
 }
@@ -733,7 +731,7 @@ static int change_needed(const MovFeatInfo *feati,
   int r;
   r= startpoint<0 ||
     (target - startpoint) / feati->weight % feati->posns;
-  oprintf(DUPO("movpos/change-needed") "%s:%s(%d*%d) %d..%d => %d\n",
+  DPRINTF(movpos,changeneeded, "%s:%s(%d*%d) %d..%d => %d\n",
 	  methods[feati->kind]->pname, feati->pname,
 	  feati->posns, feati->weight,
 	  startpoint, target, r);
@@ -749,12 +747,12 @@ static int evaluate_target(Segment *move, MovPosComb target,
   const MovFeatInfo *feati;
   MovFeatKind kind;
 
-  oprintf(DUPO("movpos/eval") "%s/%s <-%s\n", move->i->pname,
+  DPRINTF(movpos,eval, "%s/%s <-%s\n", move->i->pname,
 	  movpos_pname(move,target), movpos_pname(move,startpoint));
 
   if (startpoint<0) {
     startpoint= movpos_poscomb_actual(move);
-    oprintf(DUPO("movpos/eval") "  actual <-%s\n",
+    DPRINTF(movpos,eval, "  actual <-%s\n",
 	    movpos_pname(move,startpoint));
   }
 
@@ -768,7 +766,7 @@ static int evaluate_target(Segment *move, MovPosComb target,
   }
 
   if (kind_r) *kind_r= kind;
-  oprintf(DUPO("movpos/eval") "changes=%d kind=%s\n",
+  DPRINTF(movpos,eval, "changes=%d kind=%s\n",
 	  tchanges, methods[kind]->pname);
   return tchanges;
 }
@@ -825,10 +823,10 @@ ErrorCode movpos_change(Segment *move, MovPosComb target,
     actual= move->motion->actual;
   }
 
-  oprintf(DUPO("movpos/change") "%s/%s maxdelay=%dms actual=%s\n",
+  DPRINTF(movpos,change, "%s/%s maxdelay=%dms actual=%s\n",
 	  move->i->pname, movpos_pname(move,target),
 	  maxdelay_ms, movpos_pname(move, actual));
-  if (chg) oprintf(DUPO("movpos/change") " chg=%s:%s/%s\n",
+  if (chg) DPRINTF(movpos,change, " chg=%s:%s/%s\n",
 		   chg->meth->pname, chg->move->i->pname,
 		   movpos_pname(chg->move, chg->intent));
 
@@ -864,10 +862,10 @@ ErrorCode movpos_change(Segment *move, MovPosComb target,
     }
     chg->actual= actual;
 
-    oprintf(DUPO("movpos/change") "confirm %s:%d...\n",
+    DPRINTF(movpos,change, "confirm %s:%d...\n",
 	    meth->pname, n_motions);
     ec= meth->confirm(meth, chg, move, n_motions, motions, maxdelay_ms);
-    oprintf(DUPO("movpos/change") "confirm => %s\n",errorcodelist[ec]);
+    DPRINTF(movpos,change, "confirm => %s\n",errorcodelist[ec]);
     if (ec) goto x;
   }
   return 0;
@@ -884,7 +882,7 @@ movpos_reserve(Segment *move, int maxdelay_ms, MovPosChange **res_r,
   ErrorCode ec;
   int nchanges;
 
-  oprintf(DUPO("movpos/reserve") "%s/%s maxdelay=%dms startpoint=%s\n",
+  DPRINTF(movpos,reserve, "%s/%s maxdelay=%dms startpoint=%s\n",
 	  move->i->pname, movpos_pname(move,target),
 	  maxdelay_ms, movpos_pname(move,startpoint));
 
@@ -892,11 +890,11 @@ movpos_reserve(Segment *move, int maxdelay_ms, MovPosChange **res_r,
   if (nchanges==-1) return EC_MovFeatKindsCombination;
 
   Method *meth= methods[kind];
-  oprintf(DUPO("movpos/reserve") "allocate %s:%d...\n",
+  DPRINTF(movpos,reserve, "allocate %s:%d...\n",
 	  meth->pname, nchanges);
   Change *chg= mp_allocate(meth, move, nchanges, target);
   ec= meth->reserve(meth, chg, move, maxdelay_ms);
-  oprintf(DUPO("movpos/reserve") "reserve => %s\n",errorcodelist[ec]);
+  DPRINTF(movpos,reserve, "reserve => %s\n",errorcodelist[ec]);
   if (ec) goto x;
 
   *res_r= chg;
@@ -909,7 +907,7 @@ movpos_reserve(Segment *move, int maxdelay_ms, MovPosChange **res_r,
 
 void movpos_unreserve(MovPosChange *res) {
   if (!res) return;
-  oprintf(DUPO("movpos/unreserve") "%s:%s/%s\n",
+  DPRINTF(movpos,unreserve, "%s:%s/%s\n",
 	  res->meth->pname, res->move->i->pname,
 	  movpos_pname(res->move, res->intent));
   res->meth->destroy(res->meth, res);
diff --git a/hostside/obc.c b/hostside/obc.c
index c522afb..deedb72 100644
--- a/hostside/obc.c
+++ b/hostside/obc.c
@@ -59,15 +59,9 @@ static void *writeable(oop_source *evts, int fd,
   return OOP_CONTINUE;
 }
 
-static void addlink(OutBufferChain *ch, OutBuffer *ob) {
-  if (ch->logcopy) {
-    size_t r;
-    r= fwrite(ob->m,1,ob->l,ch->logcopy);
-    if (r!=ob->l) {
-      assert(ferror(ch->logcopy));
-      ch->error(ch,"write log",strerror(errno));
-    }
-  }
+static void addlink(OutBufferChain *ch, OutBuffer *ob,
+		    CopyCallBack *ccb, void *ccbu) {
+  if (ccb) ccb(ob->m,ob->l,ccbu);
   if (!ch->obs.head && events) /* in simulation, events==0 */
     events->on_fd(events, ch->fd, OOP_WRITE, writeable, ch);
   LIST_LINK_TAIL(ch->obs, ob);
@@ -97,14 +91,19 @@ void obc_init(OutBufferChain *ch) {
   if (r) diee("nonblock(OutBufferChain->fd,1)");
 }
 
-void ovprintf(OutBufferChain *ch, const char *fmt, va_list al) {
+void ovprintf_ccb(OutBufferChain *ch, CopyCallBack *ccb, void *ccbu,
+		   const char *fmt, va_list al) {
   OutBuffer *ob;
 
   ob= mmalloc(sizeof(*ob));
   ob->l= vasprintf(&ob->m, fmt, al);
   if (ob->l < 0) diem();
   if (!ob->l) { free(ob->m); free(ob); return; }
-  addlink(ch, ob);
+  addlink(ch,ob,ccb,ccbu);
+}
+
+void ovprintf(OutBufferChain *ch, const char *fmt, va_list al) {
+  ovprintf_ccb(ch,0,0,fmt,al);
 }
 
 void oprintf(OutBufferChain *ch, const char *msg, ...) {
@@ -126,5 +125,5 @@ void owrite(OutBufferChain *ch, const char *data, int l) {
   ob->l= l;
   ob->m= mmalloc(l);
   memcpy(ob->m, data, l);
-  addlink(ch,ob);
+  addlink(ch,ob,0,0);
 }
diff --git a/hostside/persist.c b/hostside/persist.c
index 5cbf567..85215e2 100644
--- a/hostside/persist.c
+++ b/hostside/persist.c
@@ -134,7 +134,7 @@ static int persist_convert(const char *data, const char *conv) {
 
 static int try(const char *data, const char *conv) {
   if (!persist_convert(data,conv)) return 0;
-  oprintf(UPO, "info : converted %s using %s\n",data,conv);
+  ouprintf("info : converted %s using %s\n",data,conv);
   return 1;
 }
 
diff --git a/hostside/realtime.c b/hostside/realtime.c
index f001b1d..40e1b29 100644
--- a/hostside/realtime.c
+++ b/hostside/realtime.c
@@ -28,7 +28,7 @@ static void *read_exception(oop_source *evts, int fd,
   char bufc;
   int r;
 
-  ch= (fd==UPO->fd ? UPO->desc :
+  ch= (fd==cmdi.out.fd ? cmdi.out.desc :
        fd==serial_fd ? "serial port" :
        0);
   
@@ -40,7 +40,7 @@ static void *read_exception(oop_source *evts, int fd,
   return OOP_CONTINUE;
 }
 
-/*---------- logging etc. ----------*/
+/*---------- logging and output ----------*/
 
 void safety_vpanic(Train *tra, Segment *seg,const char *fmt,va_list al) {
   char *msg;
@@ -64,6 +64,26 @@ void safety_panic(Train *tra, Segment *seg, const char *fmt, ...) {
   safety_vpanic(tra, seg, fmt, al);
 }
 
+void ouvprintf(const char *fmt, va_list al) {
+  ovprintf_ccb(&cmdi.out, simlog_ccb,0, fmt,al);
+}
+void ouprintf(const char *fmt, ...) {
+  va_list al;
+  va_start(al,fmt);
+  ouvprintf(fmt,al);
+  va_end(al);
+}
+
+void do_dvprintf(const char *fmt, va_list al) {
+  ovprintf(&cmdi.out, fmt,al);
+}
+void do_dprintf(const char *fmt, ...) {
+  va_list al;
+  va_start(al,fmt);
+  do_dvprintf(fmt,al);
+  va_end(al);
+}
+
 /*---------- printing nmra data ----------*/
 
 typedef struct {
@@ -144,44 +164,44 @@ static void opn_idle(void *u, int idle) {
   int largers= idle / base;
   int units= idle % base;
 
-  oprintf(UPO," %.*s%.*s%.*s",
+  ouprintf(" %.*s%.*s%.*s",
 	  units/2, dots,
 	  largers, ":::::::" /* enough */,
 	  (units+1)/2, dots);
 }
-static void opn_error(void *u, int rc) { oprintf(UPO," %c",rc); }
+static void opn_error(void *u, int rc) { ouprintf(" %c",rc); }
 static void opn_packet(void *u, const Nmra *n) {
   int i;
   const char *delim= " <";
   for (i=0; i<n->l; i++) {
-    oprintf(UPO,"%s%02x",delim,n->d[i]);
+    ouprintf("%s%02x",delim,n->d[i]);
     delim=" ";
   }
-  oprintf(UPO,">");
+  ouprintf(">");
 }
 
 static void oprint_nmradata(const PicInsn *pi) {
-  oprintf(UPO,"picio out nmradata");
+  ouprintf("picio out nmradata");
   nmra_decodeforpic(pi, opn_idle,opn_packet,opn_error, 0);
-  oprintf(UPO,"\n");
+  ouprintf("\n");
 }
   
 /*---------- command channel handling (oop_read, obc) ----------*/
 
 int vbadcmd(ParseState *ps, const char *fmt, va_list al) {
-  oprintf(UPO,"ack %s BadCmd : ", current_cmd?current_cmd->name:"?");
-  ovprintf(UPO,fmt,al);
-  oprintf(UPO,"\n");
+  ouprintf("ack %s BadCmd : ", current_cmd?current_cmd->name:"?");
+  ouvprintf(fmt,al);
+  ouprintf("\n");
   return EC_BadCmd;
 }
 
 void oupicio(const char *dirn, const PicInsnInfo *pii, int obj, int v) {
   if (!pii->argsbits)
-    oprintf(UPO, "picio %s %s\n", dirn, pii->name);
+    ouprintf("picio %s %s\n", dirn, pii->name);
   else if (!pii->vbits)
-    oprintf(UPO, "picio %s %s %#x\n", dirn, pii->name, obj);
+    ouprintf("picio %s %s %#x\n", dirn, pii->name, obj);
   else
-    oprintf(UPO, "picio %s %s %#x %d\n", dirn, pii->name, obj, v);
+    ouprintf("picio %s %s %#x %d\n", dirn, pii->name, obj, v);
 }
 
 static void obc_error(OutBufferChain *ch, const char *e1, const char *e2) {
@@ -193,18 +213,18 @@ static void obc_error(OutBufferChain *ch, const char *e1, const char *e2) {
 }
 
 void ouhexo(const char *word, const Byte *command, int length) {
-  oprintf(UPO, "%s", word);
-  while (length--) oprintf(UPO, " %02x", *command++);
-  oprintf(UPO, "\n");
+  ouprintf("%s", word);
+  while (length--) ouprintf(" %02x", *command++);
+  ouprintf("\n");
 }
 void ouhexi(const char *word, const Byte *command, int length) {
   ouhexo(word,command,length);
 }
- 
+
 void die_vprintf_hook(const char *fmt, va_list al) {
   static int recursing;
   if (!recursing++)
-    ovprintf(UPO, fmt, al);
+    ouvprintf(fmt, al);
   recursing--;
 }
  
@@ -215,7 +235,7 @@ void die_hook(void) {
   enco_pic_off(&off);
   
   write(serial_fd,off.d,off.l);
-  e= events ? obc_tryflush(UPO) : 0;
+  e= events ? obc_tryflush(&cmdi.out) : 0;
   if (e) fprintf(stderr,"(unwritten command output: %s)\n",strerror(e));
 }
 
@@ -265,15 +285,15 @@ void serial_transmit(const PicInsn *pi) {
     SEG_IV;
     const char *delim;
     
-    oprintf(UPO,"picio out polarity <");
+    ouprintf("picio out polarity <");
     delim="";
     FOR_SEG {
       if (!segi->invertible) continue;
       if (!picinsn_polarity_testbit(pi,segi)) continue;
-      oprintf(UPO,"%s%s", delim, segi->pname);
+      ouprintf("%s%s", delim, segi->pname);
       delim= ",";
     }
-    oprintf(UPO,">\n");
+    ouprintf(">\n");
   } else if (pi->d[0] == 0xff) {
     if (picio_send_noise < 3)
       suppress= 1;
@@ -282,7 +302,7 @@ void serial_transmit(const PicInsn *pi) {
   } else {
     picinsn_decode(pi, pic_command_infos, &pii, &obj, &v);
     if (!pii)
-      oprintf(UPO, "picio out unknown\n");
+      ouprintf("picio out unknown\n");
     else if (pii->noiselevel > picio_send_noise)
       suppress= 1;
     else
@@ -298,6 +318,122 @@ void serial_transmit(const PicInsn *pi) {
   serial_transmit_now(pi->d, pi->l);
 }
 
+/*---------- debugging ----------*/
+
+#define DEFDFLAGS_safety ~(DBIT_safety_predictplan|DBIT_safety_predictseg)
+#define DEFDFLAGS_movpos ~(DBIT_movpos_eval|DBIT_movpos_changeneeded)
+#define DEFDFLAGS_speed ~(DBIT_speed_query)
+
+#define DEBUG_FLAGS_H_DEFINE
+#include "realtime+dflags.h"
+
+static int debug_simulate_exactly;
+
+static void debug_user_set(const DebugSelectorAreaInfo *dsai,
+			   int op, unsigned long bits) {
+  switch (op) {
+  case '+':  *dsai->dflags |=  bits;  break;
+  case '-':  *dsai->dflags &= ~bits;  break;
+  default: abort();
+  }
+  *dsai->userset |= bits;
+}
+
+static void debug_arg_spec(const char *arg) {
+  /* syntaxes:
+   *  -D+
+   *  -D-
+   *  -D+<area>
+   *  -D-<area>
+   *  -D<area><kinds>
+   * eg:
+   *  -D<area>+<kind>[<kinds>...]
+   *  -D<area>-<kind>[<kinds>...]
+   * where <kind> can be `*'
+   */
+  int wlen, l, alen, op=0;
+  const char *delim, *area;
+  const DebugSelectorAreaInfo *dsai=0;
+  const DebugSelectorKindInfo *dski;
+  unsigned long bits;
+
+  if (!strcmp("=",arg)) { debug_simulate_exactly= 1; return; }
+
+  for (;;) {
+    /* possibilities, arg points to |   dsai   op
+     *  -D|                              0      undef
+     *  -D|?                             0      undef
+     *  -D|?<area>                       0      undef
+     *  -D|<area>?...                    0      undef
+     *  -D<area>...?|<kind>            <area>   char `?'
+     *  -D<area>...?|<kind>?...        <area>   1st `?'
+     */
+
+    wlen= strcspn(arg,"+-");
+    delim= &arg[wlen];
+
+    if (!dsai) { /* -D|... */
+      if (!*delim) badusage("-D without any + - or =");
+      if (wlen) { /* -D|<area>?... */
+	area= arg;
+	alen= wlen;
+      } else { /* -D|?[<area>] */
+	area= arg+1;
+	alen= strlen(area);
+	if (!alen) { /* -D|? */
+	  for (dsai=dsais; dsai->name; dsai++)
+	    debug_user_set(dsai,*delim,~0UL);
+	  return;
+	}
+      }
+      /* -D|<area>?... or -D?<area> */
+      for (dsai=dsais; dsai->name; dsai++) {
+	l= strlen(dsai->name);
+	if (l==alen && !memcmp(dsai->name,area,l)) goto area_found;
+      }
+      badusage("unknown debug message area");
+    area_found:
+      if (!wlen) { /* -D|?<area> */
+	debug_user_set(dsai,*delim,~0UL);
+	return;
+      }
+      /* -D|<area>?<kind>... */
+    } else { /* -D<area>...?|<kind>[?...] */
+      if (wlen==1 && arg[0]=='*') {
+	bits= ~0UL;
+	goto kind_found;
+      }
+      for (dski=dsai->kinds; dski->name; dski++) {
+	l= strlen(dski->name);
+	if (l==wlen && !memcmp(dski->name,arg,l)) {
+	  bits= dski->bit;
+	  goto kind_found;
+	}
+      }
+      badusage("unknown debug message kind");
+    kind_found:
+      debug_user_set(dsai,op,bits);
+      if (!*delim) /* -D<area>...?|<kind> */
+	return;
+       /* -D<area>...?|<kind>?<kind>... */
+    }
+    /* -D...?|<something>?<kind>... */
+    op= *delim++;
+    arg= delim;
+    /* -D...?<something>?|<kind>... */
+  }
+}    
+
+static void debug_setup(void) {
+  const DebugSelectorAreaInfo *dsai;
+  unsigned long def;
+
+  for (dsai=dsais; dsai->name; dsai++) {
+    def= (simulate && !debug_simulate_exactly) ? ~0UL : dsai->defdflags;
+    *dsai->dflags |= def & ~*dsai->userset;
+  }
+}
+
 /*---------- initialisation ----------*/
 
 int main(int argc, const char **argv) {
@@ -322,6 +458,7 @@ int main(int argc, const char **argv) {
       case 'V': simlog_full=1;                           break;
       case 'L': logcopy_fn= arg;                  arg=0; break;
       case 'S': simulate= arg;                    arg=0; break;
+      case 'D':	debug_arg_spec(arg);              arg=0; break;
       case 'R':
 	rtfeats_use= 0;
 	while ((c= *arg++)) {
@@ -346,6 +483,8 @@ int main(int argc, const char **argv) {
   cmdi.out.error= obc_error;
   cmdi.doline= command_doline;
 
+  debug_setup();
+
   if (!simulate) {
     sys_events= oop_sys_new();  if (!sys_events) diee("oop_sys_new");
     events= oop_sys_source(sys_events);  massert(events);
diff --git a/hostside/realtime.h b/hostside/realtime.h
index 5d844c7..6686336 100644
--- a/hostside/realtime.h
+++ b/hostside/realtime.h
@@ -29,6 +29,7 @@
 #include <dirent.h>
 
 #include "../layout/layout-data.h"
+#include "realtime+dflags.h"
 
 typedef struct Segment Segment;
 typedef struct Train Train;
@@ -112,8 +113,6 @@ extern FeaturesAddr *feataddrs;
 extern CommandInput cmdi;
 extern int picio_send_noise;
 
-#define UPO (&(cmdi.out))
-
 #define CIXF_U                 0x0000ffffu
 #define CIXF_FORCE             0x00010000u
 #define CIXF_ANYSTA            0x00020000u
@@ -165,6 +164,7 @@ void serial_indata_process(int buf_used);
 void sim_initialise(const char *logduplicate);
 void sim_run(void);
 
+void simlog_ccb(char *m, size_t l, void *u);
 void simlogv(const char *fmt, va_list al);
 void simlog(const char *fmt, ...);
 void simlog_serial(const Byte *data, int length);
@@ -232,18 +232,30 @@ void realtime_priority(void);
 
 extern unsigned rtfeats_use;
 
+void ouvprintf(const char *fmt, va_list al);
+void ouprintf(const char *fmt, ...);
+
+void do_dvprintf(const char *fmt, va_list al);
+void do_dprintf(const char *fmt, ...);
+
+#define DEBUGP(a,k) (dflags_##a & DBIT_##a##_##k)
+
+#define COND_DPRINTF(cond, a,k, fmt, ...) \
+  ((cond) ? do_dprintf("debug " #a "/" #k " : " fmt,##__VA_ARGS__) : (void)0)
+
+#define DPRINTF(a,k,f,...) COND_DPRINTF(DEBUGP(a,k),a,k,f,##__VA_ARGS__)
+#define DPRINTF1(a,k,f,...) COND_DPRINTF((DP)=DEBUGP(a,k), a,k,f,##__VA_ARGS__)
+#define DPRINTF2(f,...) ((DP) ? do_dprintf(f,##__VA_ARGS__) : (void)0)
+
 /*---------- tbi ----------*/
 
 void choreographers_all_abandon(void);
 
-#define DUPO(ctx) UPO, "debug " ctx " : "
-
 #include "record.h"
 
 #define PERSIST_CONVERT_OPTION "--persist-convert-entrails"
 
 #include "safety.h"
 
-#define CTYPE(isfoobar,ch) (isfoobar((unsigned char)(ch)))
 
 #endif /*REALTIME_H*/
diff --git a/hostside/resolve.c b/hostside/resolve.c
index 7a35f99..87947d0 100644
--- a/hostside/resolve.c
+++ b/hostside/resolve.c
@@ -163,14 +163,14 @@ static int resmain_getmovpos(TrackLocation *t, TrackAdvanceContext *c,
   if (d->home && d->home->resolution == RR_H) {
     d->tr_backwards= d->ho_backwards;
     *use_io= 0; /* a bit kludgey */
-    oprintf(DUPO("resolving") " resmain  getmovpos %s H\n", pn);
+    DPRINTF(resolving,main, "getmovpos %s H\n", pn);
   } else if (d->owner) {
     d->tr_backwards ^= d->owner->backwards;
     *use_io= d->movposcomb;
-    oprintf(DUPO("resolving") " resmain  getmovpos %s E %u\n", pn, *use_io);
+    DPRINTF(resolving,main, "getmovpos %s E %u\n", pn, *use_io);
   } else {
     *use_io= -1;
-    oprintf(DUPO("resolving") " resmain  getmovpos %s N -1\n", pn);
+    DPRINTF(resolving,main, "getmovpos %s N -1\n", pn);
   }
   return 0;
 }
@@ -199,16 +199,16 @@ static int resolve_complete_main(void) {
 
   for (phase=0; phase<3; phase=nextphase) {
     nextphase= phase+1;
-    oprintf(DUPO("resolving") "iteration %c\n", "EHX"[phase]);
+    DPRINTF(resolving,alg, "iteration %c\n", "EHX"[phase]);
 
-    oprintf(DUPO("resolving") " calculate-u\n");
+    DPRINTF(resolving,alg, " calculate-u\n");
 
     FOR_SEGMENT(d,NOOP,NOOP) { /* calculate U */
       unsigned updated= 0;
 
 #define ADDTO_U_EH(homeowner,HH_HE,string)				\
       if (d->homeowner && d->homeowner->resolution == HH_HE) {		\
-	oprintf(DUPO("resolving") "  covered %s " string " %s\n",	\
+	DPRINTF(resolving,alg, "  covered %s " string " %s\n",	\
 		di->pname, d->homeowner->pname);			\
 	updated++;							\
       }
@@ -220,30 +220,30 @@ static int resolve_complete_main(void) {
       d->iselem_u= updated;
     }
 
-    oprintf(DUPO("resolving") " searching\n");
+    DPRINTF(resolving,alg, " searching\n");
     FOR_SEGMENT(d, NOOP, NOOP) {
       if (!(d->res_detect && !d->iselem_u))
 	continue;
       /* 3. we have a violation of D \subset U, namely d */
 
-      oprintf(DUPO("resolving") "  violation %s\n", di->pname);
+      DPRINTF(resolving,alg, "  violation %s\n", di->pname);
 
       if (d->owner) { /* 3a perhaps */
 	t= d->owner;
-	oprintf(DUPO("resolving") "   expected %s\n", t->pname);
+	DPRINTF(resolving,alg, "   expected %s\n", t->pname);
 
 	if (t->addr < 0) {
-	  oprintf(DUPO("resolving") "    expected-is-not-addressable\n");
+	  DPRINTF(resolving,alg, "    expected-is-not-addressable\n");
 	  goto not_3a;
 	}
 
 	if (t->resolution == RR_H) {
-	  oprintf(DUPO("resolving") "    expected-is-at-home\n");
+	  DPRINTF(resolving,alg, "    expected-is-at-home\n");
 	  goto not_3a;
 	}
 
 	if (d->movposcomb < 0) {
-	  oprintf(DUPO("resolving") "    track-unknown-position\n");
+	  DPRINTF(resolving,alg, "    track-unknown-position\n");
 	  goto not_3a;
 	}
 
@@ -258,7 +258,7 @@ static int resolve_complete_main(void) {
 	  if (d1->owner == t && d1->iselem_u) {
 	    FOR_TRAIN(t2, NOOP, NOOP) {
 	      if (t2->resolution == RR_H && d1->owner == t2) {
-		oprintf(DUPO("resolving") "    clash %s %s\n",
+		DPRINTF(resolving,alg, "    clash %s %s\n",
 			d1i->pname, t2->pname);
 		clashes++;
 	      }
@@ -266,7 +266,7 @@ static int resolve_complete_main(void) {
 	  }
 	}
 	if (clashes) {
-	  oprintf(DUPO("resolving") "   expected-has-clashes\n");
+	  DPRINTF(resolving,alg, "   expected-has-clashes\n");
 	  goto not_3a;
 	}
 
@@ -274,7 +274,7 @@ static int resolve_complete_main(void) {
 	t->resolution= RR_E;
 	nextphase= 0;
       already_3a:
-	oprintf(DUPO("resolving") "   supposing %s as-expected\n", t->pname);
+	DPRINTF(resolving,alg, "   supposing %s as-expected\n", t->pname);
 	continue;
       }
     not_3a:
@@ -284,17 +284,17 @@ static int resolve_complete_main(void) {
 	  continue;
 
 	Train *t1= d->home; /* t' st d \elem H(t') */
-	oprintf(DUPO("resolving") "   home %s\n", t1->pname);
+	DPRINTF(resolving,alg, "   home %s\n", t1->pname);
 	
 	if (t1->addr < 0) {
-	  oprintf(DUPO("resolving") "    home-is-not-addressable\n");
+	  DPRINTF(resolving,alg, "    home-is-not-addressable\n");
 	  goto not_3b;
 	}
 
-	oprintf(DUPO("resolving") "   reset-expecteds\n");
+	DPRINTF(resolving,alg, "   reset-expecteds\n");
 	FOR_TRAIN(tplus, NOOP,NOOP) {
 	  if (tplus->resolution == RR_E) {
-	    oprintf(DUPO("resolving") "   supposing %s absent\n", tplus->pname);
+	    DPRINTF(resolving,alg, "   supposing %s absent\n", tplus->pname);
 	    tplus->resolution= RR_N;
 	    nextphase= 0;
 	  }
@@ -310,7 +310,7 @@ static int resolve_complete_main(void) {
 	t1->resolution= RR_H;
 	nextphase= 0;
 
-	oprintf(DUPO("resolving") "   supposing %s at-home\n", t1->pname);
+	DPRINTF(resolving,alg, "   supposing %s at-home\n", t1->pname);
 	continue;
       }
     not_3b:
@@ -319,7 +319,7 @@ static int resolve_complete_main(void) {
       if (phase<2)
 	continue;
 
-      oprintf(UPO, "resolution inexplicable %s\n", di->pname);
+      ouprintf("resolution inexplicable %s\n", di->pname);
       d->res_detect= 0;
       problems++;
     }
@@ -353,9 +353,9 @@ static int resolve_complete_main(void) {
 	assert(!d->motion);
 	ErrorCode ec= movpos_reserve(d,-1,&d->motion,target,-1);
 	if (ec) {
-	  oprintf(UPO, "resolution movpos-change-failed %s/%s %s\n",
-		  d->i->pname, d->i->poscombs[target].pname,
-		  errorcodelist[ec]);
+	  ouprintf("resolution movpos-change-failed %s/%s %s\n",
+		   d->i->pname, d->i->poscombs[target].pname,
+		   errorcodelist[ec]);
 	  problems++;
 	}
       }
@@ -385,10 +385,10 @@ static int findends_getmovpos(TrackLocation *t, TrackAdvanceContext *c,
   const char *pn= t->seg->i->pname;
   if (t->seg->motion) *use_io= movpos_change_intent(t->seg->motion);
   if (*use_io<0) {
-    oprintf(DUPO("resolving") " ends  getmovpos %s fails\n", pn);
+    DPRINTF(resolving,ends, " getmovpos %s fails\n", pn);
     return -1;
   }
-  oprintf(DUPO("resolving") " ends  getmovpos %s -> %d\n", pn, *use_io);
+  DPRINTF(resolving,ends, " getmovpos %s -> %d\n", pn, *use_io);
   return 0;
 }
 
@@ -407,7 +407,7 @@ static int segdist(Segment *seg) {
 
 static void ends_callback_debug(const char *what, TrackLocation *t,
 				struct TrackAdvanceContext *c) {
-  oprintf(DUPO("resolving") " ends   %s"
+  DPRINTF(resolving,ends, "  %s"
 	  " %s%s dist=%d det=%d ours=%d done=%d owner=%s home=%s\n",
 	  what, t->backwards?"-":"", t->seg->i->pname, c->distance,
 	  t->seg->res_detect,
@@ -457,7 +457,7 @@ static int resolve_complete_ends_train(Train *tra) {
   default: abort();
   }
 
-  oprintf(DUPO("resolving") " ends %s %c\n",
+  DPRINTF(resolving,ends, "%s %c\n",
 	  tra->pname, RESOLUTION_CHARS[tra->resolution]);
 
   startpoint= 0;
@@ -488,20 +488,20 @@ static int resolve_complete_ends_train(Train *tra) {
   u.extraspace= MARGIN_NOSE + tra->head;
   u.furthest= 0;
 
-  oprintf(DUPO("resolving") " ends  start=%s%s es=%d\n",
+  DPRINTF(resolving,ends, " start=%s%s es=%d\n",
 	  t.backwards?"-":"", t.seg->i->pname, u.extraspace);
 
   trackloc_advance(&t,&tc);
 
-  oprintf(DUPO("resolving") " ends  es=%d furthest=%s fd=%s%s fd.dist=%d\n",
+  DPRINTF(resolving,ends, " es=%d furthest=%s fd=%s%s fd.dist=%d\n",
 	  u.extraspace, u.furthest->i->pname,
 	  tra->foredetect->tr_backwards?"-":"", tra->foredetect->i->pname,
 	  segdist(tra->foredetect));
 
   tra->maxinto= segdist(tra->foredetect) - u.extraspace;
   if (tra->maxinto < 0) {
-    oprintf(UPO, "resolution mispositioned head %s %s %d\n",
-	    tra->pname, tra->foredetect->i->pname, -tra->maxinto);
+    ouprintf("resolution mispositioned head %s %s %d\n",
+	     tra->pname, tra->foredetect->i->pname, -tra->maxinto);
     return 1;
   }
   tra->uncertainty= tra->maxinto;
@@ -515,15 +515,15 @@ static int resolve_complete_ends_train(Train *tra) {
 
   trackloc_advance(&t,&tc);
 
-  oprintf(DUPO("resolving") " ends  maxi=%d unc=%d;"
+  DPRINTF(resolving,ends, " maxi=%d unc=%d;"
 	  " remaining distance=%d\n",
 	  tra->maxinto, tra->uncertainty, tc.distance);
 
   if (tc.distance) {
     tra->uncertainty -= tc.distance;
     if (tra->uncertainty < 0) {
-      oprintf(UPO, "resolution mispositioned tail %s %s %d\n",
-	      tra->pname, t.seg->i->pname, -tra->uncertainty);
+      ouprintf("resolution mispositioned tail %s %s %d\n",
+	       tra->pname, t.seg->i->pname, -tra->uncertainty);
       return 1;
     }
   }
@@ -586,7 +586,7 @@ int resolve_complete(void) {
     problems += resolve_complete_ends();
 
   if (problems) {
-    oprintf(UPO,"resolution problems %d\n",problems);
+    ouprintf("resolution problems %d\n",problems);
     return -1;
   }
 
diff --git a/hostside/safety.c b/hostside/safety.c
index 289fac3..fb0fd3f 100644
--- a/hostside/safety.c
+++ b/hostside/safety.c
@@ -314,7 +314,7 @@ static ErrorCode predict_vproblem(PredictUserContext *u, Segment *seg,
   l= vasprintf(&message, fmt, al);  if (l <= 0) diem();
 
   if (u->optimistic)
-    oprintf(DUPO("safety") " predict   optimistic problem %s\n", message);
+    DPRINTF(safety,predict,"   optimistic problem %s\n", message);
   else if (!u->problem_callback)
     safety_panic(u->train, seg, "unexpected problem predicted"
 		 " (context: %s): %s", (char*)u->problem_callback_u, message);
@@ -345,7 +345,7 @@ static void pred_callback_debug(const char *what, TrackLocation *t,
 				const TrackLocation *before) {
   PredictUserContext *u= c->u;
   
-  oprintf(DUPO("safety") " predict   %s"
+  DPRINTF(safety,predictseg,"   %s"
 	  " %c%s dist=%-4d until=%-4ld %c%c%c.%c (was %s%s..%d dist=%-4d)"
 	  "  %c%c%c.%c%c%c%c elapsed=%ld la#%d"
 	  " %s/%s %c%s >%s"
@@ -589,7 +589,7 @@ static int fdet_nextseg(TrackLocation *t, TrackAdvanceContext *c,
   u->nosec.distance= advanced;
   r= trackloc_advance(&u->nose,&u->nosec);
   if (r) {
-    oprintf(DUPO("safety") " predict   fdet_nextseg  r=%s\n",ec2str(r));
+    DPRINTF(safety,predictseg,"   fdet_nextseg  r=%s\n",ec2str(r));
     return r;
   }
 
@@ -690,6 +690,7 @@ ErrorCode predict(Train *tra, struct timeval tnow, unsigned flags,
   Segment *foredet;
   SEG_IV;
   ErrorCode ec;
+  int DP;
 
   memset(&u,0,sizeof(u));
   u.train= tra;
@@ -703,7 +704,7 @@ ErrorCode predict(Train *tra, struct timeval tnow, unsigned flags,
   u.desire_move= desire_move;
   u.desire_movposcomb= desire_movposcomb;
 
-  oprintf(DUPO("safety") " predict ***starting*** %s%s maxspeed=%f"
+  DPRINTF(safety,core," ***predicting*** %s%s maxspeed=%f"
 	  " (speed %f try %f, step %d%s) stopdist=%d flags=%c%c%s"
 	  " desire=%s/%s\n",
 	  tra->backwards?"-":"",tra->pname,
@@ -809,7 +810,7 @@ ErrorCode predict(Train *tra, struct timeval tnow, unsigned flags,
   if (tra->autopoint) {
     Distance min_autopoint_dist= MARGIN_AUTOPOINTTIME * u.maxspeed;
 
-    oprintf(DUPO("safety") " predict  optimism %d (min %d) nose %s\n",
+    DPRINTF(safety,predict,"  optimism %d (min %d) nose %s\n",
 	    u.autopoint_distance, min_autopoint_dist, u.nose.seg->i->pname);
 
     if (u.autopoint_distance < min_autopoint_dist)
@@ -834,33 +835,32 @@ ErrorCode predict(Train *tra, struct timeval tnow, unsigned flags,
 
   /*----- commit to the plan -----*/
 
-  oprintf(DUPO("safety") " predict  committing la#%d\n",
+  DPRINTF(safety,predict,"  committing la#%d\n",
 	  u.lookahead);
 
   tra->plan_lookahead_nsegs= u.lookahead;
 
   if (u.need_polarise) {
-    oprintf(DUPO("safety") " predict  polarising train_polarity=%d\n",
+    DPRINTF(safety,predict,"  polarising train_polarity=%d\n",
 	    u.train_polarity_inverted),
     actual_inversions_start();
   }
 
-  oprintf(DUPO("safety") " predict  ");
+  DPRINTF1(safety,predictplan,"  ");
   FOR_SEG {
-    oprintf(UPO,
-	    " %s%s%s%c%c%c%c/%s%s%s%s%s",
-	    seg->tr_backwards?"-":"", seg->i->pname,
-	    seg->owner == tra ? "=" : seg->owner ? "#" : "-",
-	    "-N"[ seg->now_present ],
-	    "-P"[ seg->pred_present ],
-	    "-V"[ seg->pred_vacated ],
-	    "-p"[ seg->will_polarise ],
-	    movpos_pname(seg,seg->movposcomb),
-	    seg->motion ? (seg->moving ? "!" : "~") : "",
-	    seg->motion ? motion_pname(seg,seg->motion) : "",
-	    seg->motion_newplan ? ">" : "",
-	    seg->motion && seg->motion_newplan==seg->motion ? "=" :
-	      motion_pname(seg,seg->motion_newplan));
+    DPRINTF2(" %s%s%s%c%c%c%c/%s%s%s%s%s",
+	     seg->tr_backwards?"-":"", seg->i->pname,
+	     seg->owner == tra ? "=" : seg->owner ? "#" : "-",
+	     "-N"[ seg->now_present ],
+	     "-P"[ seg->pred_present ],
+	     "-V"[ seg->pred_vacated ],
+	     "-p"[ seg->will_polarise ],
+	     movpos_pname(seg,seg->movposcomb),
+	     seg->motion ? (seg->moving ? "!" : "~") : "",
+	     seg->motion ? motion_pname(seg,seg->motion) : "",
+	     seg->motion_newplan ? ">" : "",
+	     seg->motion && seg->motion_newplan==seg->motion ? "=" :
+	     motion_pname(seg,seg->motion_newplan));
 
     /* set ownership and det_ignore */
     if (seg->pred_present || seg->pred_vacated) {
@@ -926,7 +926,7 @@ ErrorCode predict(Train *tra, struct timeval tnow, unsigned flags,
     seg->now_present= seg->pred_present=
       seg->pred_vacated= seg->will_polarise= 0;
   }
-  oprintf(UPO,"\n");
+  DPRINTF2("\n");
 
   if (u.need_polarise)
     actual_inversions_done();
@@ -941,7 +941,7 @@ ErrorCode predict(Train *tra, struct timeval tnow, unsigned flags,
   return 0;
 
  xproblem:
-  oprintf(DUPO("safety") " predict  returning %s\n", ec2str(ec));
+  DPRINTF(safety,predict,"  returning %s\n", ec2str(ec));
 
   FOR_SEG {
     seg->now_present= seg->pred_present=
@@ -965,10 +965,10 @@ ErrorCode predict(Train *tra, struct timeval tnow, unsigned flags,
 /*========== reporting position and ownership ==========*/
 
 void report_train_position(Train *tra) {
-  oprintf(UPO, "train %s %s at %s%s:%d+-%d\n",
-	  tra->pname, tra->backwards ? "backwards" : "forwards",
-	  tra->foredetect->tr_backwards?"-":"",
-	  tra->foredetect->i->pname, tra->maxinto, tra->uncertainty);
+  ouprintf("train %s %s at %s%s:%d+-%d\n",
+	   tra->pname, tra->backwards ? "backwards" : "forwards",
+	   tra->foredetect->tr_backwards?"-":"",
+	   tra->foredetect->i->pname, tra->maxinto, tra->uncertainty);
 }  
   
 static int report_getmovpos(TrackLocation *t, TrackAdvanceContext *c,
@@ -1001,13 +1001,13 @@ static int report_nextseg(TrackLocation *t, struct TrackAdvanceContext *c,
     u->usecurrentposn= 0;
   }
 
-  oprintf(UPO," %s%s", t->backwards?"-":"", t->seg->i->pname);
+  ouprintf(" %s%s", t->backwards?"-":"", t->seg->i->pname);
 
   if (t->seg->i->n_poscombs > 1) {
     r= report_getmovpos(t,c,mpc);  assert(!r);  assert(*mpc>=0);
-    oprintf(UPO,"/%s", t->seg->i->poscombs[*mpc].pname);
+    ouprintf("/%s", t->seg->i->poscombs[*mpc].pname);
   }
-  oprintf(UPO,"%s",flags);
+  ouprintf("%s",flags);
 
   return 0;
 }
@@ -1022,7 +1022,7 @@ void report_train_ownerships(Train *tra, Segment *hindmost,
   u.usecurrentposn= !always_use_motions;
   
   /* Walk along the train printing its segments: */
-  oprintf(UPO, "train %s has", tra->pname);
+  ouprintf("train %s has", tra->pname);
   
   u.nose.seg= hindmost;
   u.nose.remain= 0;
@@ -1036,7 +1036,7 @@ void report_train_ownerships(Train *tra, Segment *hindmost,
 
   trackloc_advance(&u.nose,&u.nosec);
 
-  oprintf(UPO, "\n");
+  ouprintf("\n");
 }
   
 
@@ -1044,8 +1044,8 @@ void report_train_ownerships(Train *tra, Segment *hindmost,
 
 static void detection_report_problem(Train *tra, Segment *seg,
 				     void *pu, const char *message) {
-  oprintf(UPO, "train %s signalling-problem %s : %s\n",
-	  tra->pname, seg->i->pname, message);
+  ouprintf("train %s signalling-problem %s : %s\n",
+	   tra->pname, seg->i->pname, message);
 }
 
 void safety_notify_detection(Segment *seg) {
@@ -1064,7 +1064,7 @@ void safety_notify_detection(Segment *seg) {
     if (!interferer->det_expected)
       safety_panic(0,seg, "unexpected detection, perhaps really at %s",
 		   interferer->i->pname);
-    oprintf(DUPO("safety") "detection %s using interferer %s",
+    DPRINTF(safety,core, " detection %s using interferer %s",
 	    seg->i->pname, interferer->i->pname);
     seg= interferer;
   }
diff --git a/hostside/simulate.c b/hostside/simulate.c
index 9126994..187e87e 100644
--- a/hostside/simulate.c
+++ b/hostside/simulate.c
@@ -41,8 +41,18 @@ static struct timeval sevent_abst;
 static Byte simlog_lastdet[DETSAVES][2];
 static uint32_t simlog_detcompr_lcongx;
 
+void simlog_ccb(char *m, size_t l, void *u) {
+  size_t r;
+  if (!simoutput || simoutput==stdout) return;
+
+  r= fwrite(m,1,l,simoutput);
+  if (r!=l) {
+    assert(ferror(simoutput));
+    diee("copy output to simulation log");
+  }
+}
 void simlogv(const char *fmt, va_list al) {
-  if (simoutput==stdout) ovprintf(UPO,fmt,al);
+  if (simoutput==stdout) ouvprintf(fmt,al);
   else if (simoutput) vfprintf(simoutput,fmt,al);
 }
 void simlog(const char *fmt, ...) {
@@ -52,7 +62,7 @@ void simlog(const char *fmt, ...) {
   va_end(al);
 }
 void simlog_flush(void) {
-  if (simoutput==stdout) obc_tryflush(UPO);
+  if (simoutput==stdout) obc_tryflush(&cmdi.out);
   else if (simoutput)
     if (ferror(simoutput) || fflush(simoutput))
       diee("write simulation log");
@@ -97,7 +107,6 @@ void simlog_open(const char *fn) {
   } else if (fn[0]) {
     simoutput= fopen(fn,"w");
     if (!simoutput) diee("open simulation log %s",fn);
-    cmdi.out.logcopy= simoutput;
   }
 }
 
@@ -291,7 +300,6 @@ static void se_eof(void) {
 /*---------- core ----------*/
 
 void sim_initialise(const char *logduplicate) {
-  cmdi.out.logcopy= 0;
   obc_init_core(&cmdi.out);
   serial_fd= open("/dev/null",O_WRONLY);
   if (serial_fd<0) diee("open /dev/null for dummy serial");
diff --git a/hostside/speed.c b/hostside/speed.c
index 4ad15ae..4f966b8 100644
--- a/hostside/speed.c
+++ b/hostside/speed.c
@@ -19,7 +19,7 @@ static void xmit(Train *tra) {
 static void decel_done(TimeoutEvent *toev) {
   Train *tra= (void*)((char*)toev - offsetof(Train, speed.decel));
   tra->speed.speed= tra->speedcurve[tra->speed.step];
-  oprintf(DUPO("speed") "  decel_done %s step %d speed %f\n",
+  DPRINTF(speed,core, "decel_done %s step %d speed %f\n",
 	  tra->pname, tra->speed.step, tra->speed.speed);
 }
 
@@ -36,7 +36,7 @@ static double current_speed(Train *tra, const struct timeval tnow) {
   double v1sq, v2sq, vtsq;
   double left_to_go, ts_v2, cs;
   
-  oprintf(DUPO("speed") "  current? %s try=%f decel.running=%d speed=%f"
+  DPRINTF(speed,query, "current? %s try=%f decel.running=%d speed=%f"
 	  " step=%d\n",
 	  tra->pname, tra->speed.try_speed,
 	  tra->speed.decel.running, tra->speed.speed, tra->speed.step);
@@ -48,7 +48,7 @@ static double current_speed(Train *tra, const struct timeval tnow) {
               (tra->speed.decel.abs.tv_usec - tnow.tv_usec) * 0.001;
 
   if (left_to_go <= 0) {
-    oprintf(DUPO("speed") "  current?  decel-done\n");
+    DPRINTF(speed,query, "current?  decel-done\n");
     toev_stop(&tra->speed.decel);
     decel_done(&tra->speed.decel);
     return tra->speed.speed;
@@ -63,7 +63,7 @@ static double current_speed(Train *tra, const struct timeval tnow) {
   v2sq= v2*v2;
   vtsq= v1sq + (v2sq-v1sq) * left_to_go / ts_v2;
   cs= sqrt(vtsq);
-  oprintf(DUPO("speed") "  current?  decel-inprogress v2=%f v1=%f"
+  DPRINTF(speed,query, "current?  decel-inprogress v2=%f v1=%f"
 	  " ts_v2=%f ltg=%f  returning %f\n",
 	  v2,v1, ts_v2, left_to_go, cs);
   return cs;
@@ -94,7 +94,7 @@ double speedmanager_stoppingdistance(Train *tra, struct timeval tnow) {
 int speedmanager_stopping(Train *tra) {
   int r;
   r= tra->speed.try_speed < 0 && !tra->speed.step;
-  oprintf(DUPO("speed") "  stopping? %s  returning %d\n", tra->pname, r);
+  DPRINTF(speed,query, "stopping? %s  returning %d\n", tra->pname, r);
   return r;
 }  
 
@@ -103,7 +103,7 @@ static ErrorCode request_core(Train *tra, int step, struct timeval tnow,
   ErrorCode ec, ec2;
   double vnow, vtarg;
 
-  oprintf(DUPO("speed") " request %s%s step %d\n",
+  DPRINTF(speed,core, "request %s%s step %d\n",
 	  tra->backwards?"-":"",tra->pname,
 	  step);
 
@@ -113,7 +113,7 @@ static ErrorCode request_core(Train *tra, int step, struct timeval tnow,
   vnow= current_speed(tra,tnow);
   vtarg= tra->speedcurve[step];
   
-  oprintf(DUPO("speed") " request  vnow=%f vtarg=%f\n", vnow,vtarg);
+  DPRINTF(speed,core, " request  vnow=%f vtarg=%f\n", vnow,vtarg);
 
   if (vtarg <= vnow) {
     toev_stop(&tra->speed.decel);
diff --git a/hostside/startup.c b/hostside/startup.c
index db87def..72d595b 100644
--- a/hostside/startup.c
+++ b/hostside/startup.c
@@ -81,7 +81,7 @@ static void timedout_onward(TimeoutEvent *toev) {
 static void sta_startup_manual(void) {
   waggle_startup_manual();
   retransmit_start();
-  oprintf(UPO, "stastate %s\n", stastatelist[sta_state]);
+  ouprintf("stastate %s\n", stastatelist[sta_state]);
 }
 
 void sta_startup(void) {
@@ -157,7 +157,7 @@ static void sta_goto(StartupState new_state) {
   sta_state= new_state;
 
   /* notify various people: */
-  oprintf(UPO, "stastate %s\n", stastatelist[sta_state]);
+  ouprintf("stastate %s\n", stastatelist[sta_state]);
   /* ... add others here. */
   if (sta_state == Sta_Finalising) resolve_motioncheck();
 }   
@@ -227,7 +227,7 @@ void serial_moredata(PicInsn *buf) {
 	  (pii->opcode==PICMSG_PONG && obj==pong_seq)))
       simlog_serial(buf->d, buf->l);
   
-  if (!pii) { oprintf(UPO, "picio in unknown\n"); return; }
+  if (!pii) { ouprintf("picio in unknown\n"); return; }
   if (!suppress)
     oupicio("in",pii,obj,v);
   pii->input_fn(pii,buf,obj);
@@ -276,8 +276,8 @@ void on_pic_hello(const PicInsnInfo *pii, const PicInsn *pi, int objnum)
 void on_pic_aaargh(const PicInsnInfo *pii, const PicInsn *pi, int objnum)
   { abort(); }
 void on_pic_spurious(const PicInsnInfo *pii, const PicInsn *pi, int objnum) {
-  oprintf(UPO,"warning spurious %d : spurious short circuit (fault)"
-	  " detection interrupts\n", objnum);
+  ouprintf("warning spurious %d : spurious short circuit (fault)"
+	   " detection interrupts\n", objnum);
 }
 void on_pic_pointed(const PicInsnInfo *pii, const PicInsn *pi, int objnum) { }
 void on_pic_retriable(const PicInsnInfo *pii, const PicInsn *pi, int objnum){}
@@ -292,8 +292,8 @@ static SegmentNum on_pic_detect_prep(int detyn, int objnum) {
   if (!(picio_send_noise <= 1 &&
 	segments[segn].owner &&
 	segments[segn].det_ignore))
-    oprintf(UPO,"picio in-info detect %d %s\n",
-	    detyn, info_segments[segn].pname);
+    ouprintf("picio in-info detect %d %s\n",
+	     detyn, info_segments[segn].pname);
 
   return segn;
 }
@@ -320,7 +320,7 @@ void on_pic_detect1(const PicInsnInfo *pii, const PicInsn *pi, int objnum) {
     break;
   case Sta_Finalising:
     if (!seg->res_detect) {
-      oprintf(UPO, "resolution new-detection-in-finalising @%s\n", pname);
+      ouprintf("resolution new-detection-in-finalising @%s\n", pname);
       sta_goto(Sta_Settling);
     }
     break;
diff --git a/hostside/xs.gdb b/hostside/xs.gdb
index 5073fc8..3e09513 100644
--- a/hostside/xs.gdb
+++ b/hostside/xs.gdb
@@ -5,5 +5,5 @@ break nmra_errchk_fail
 break safety_panic
 break obc_error
 #break findhead_nextseg
-set args -S+realtime.log shinkansen.speeds.record homes.record 
+set args -Dsafety-predictseg -S+realtime.log shinkansen.speeds.record homes.record 
 run