simulation tested and seems reproduceable

diff --git a/hostside/README.commands b/hostside/README.commands
index b01092872091241751b51b8324710f59f7f95603..5df572c1e6c52965daf2e49307c92ac1b2f1cc7e 100644 (file)
--- a/hostside/README.commands
+++ b/hostside/README.commands
@@ -61,8 +61,10 @@ POSSIBLY-ASYNCHRONOUS REPORTING OF MESSAGES TO/FROM (MASTER) PIC
  U< debug <context> : <debug message>
  U< info : <informational message>
 
- U> timestamp <seconds>.<microseconds>
- U> timer-event <class>.<instance>
+ S  picioh in suppressed <byte> [<byte>...]
+ S  command-in <command> <args>....
+ S  timestamp <seconds>.<microseconds>
+ S  timer-event <class>.<instance>
 
 ======================================================================
 

diff --git a/hostside/eventhelp.c b/hostside/eventhelp.c
index 1f65f4552da4f06de652d135fc4489dfe22be56f..0232a69ee16175482144106e29277440bbb6a211 100644 (file)
--- a/hostside/eventhelp.c
+++ b/hostside/eventhelp.c
@@ -12,12 +12,12 @@ void real_mgettimeofday(struct timeval *tv) {
   int r;
   r= gettimeofday(tv,0);
   if (r) diee("gettimeofday failed");
-  oprintf(UPO,"timestamp %ld.%06ld\n", tv->tv_sec, tv->tv_usec);
 }
 
 void *toev_callback(oop_source *source, struct timeval tv, void *t_v) {
   TimeoutEvent *toev= t_v;
-  oprintf(UPO,"timer-event %s.%s\n", toev->pclass, toev->pinst);
+  simlog("timer-event %s.%s\n",toev->pclass,toev->pinst);
+  simlog_flush();
   toev->running= 0;
   toev->callback(toev);
   return OOP_CONTINUE;
@@ -51,4 +51,6 @@ void mgettimeofday(struct timeval *tv) {
   } else {
     real_mgettimeofday(tv);
   }
+  simlog("timestamp %ld.%06ld\n",tv->tv_sec,tv->tv_usec);
+  simlog_flush();
 }

diff --git a/hostside/realtime.c b/hostside/realtime.c
index 731c9af2fea9e4e7151dbfa3e724528f65991788..9721fa5ceacbac44b482f0f25c56c0988167b3c9 100644 (file)
--- a/hostside/realtime.c
+++ b/hostside/realtime.c
@@ -12,7 +12,7 @@ CommandInput cmdi;
 int picio_send_noise= 1;
 
 static const char *device= "/dev/railway";
-static const char *logcopy_fn= "+realtime.log";
+static const char *logcopy_fn;
 
 /*---------- general event handling ----------*/
 
@@ -201,10 +201,12 @@ int vbadcmd(ParseState *ps, const char *fmt, va_list al) {
 static void command_doline(ParseState *ps, CommandInput *cmdi_arg) {
   int r;
 
-  oprintf(UPO, "executing %s\n",ps->remain);
+  simlog("command-in %s\n",ps->remain);
+  simlog_flush();
   ci= 0;
   ci= some_needword_lookup(ps, toplevel_cmds, "command");
   if (!ci) return;
+  oprintf(UPO, "executing %s\n",ci->name);
   r= ci->fn(ps,ci);
   switch (r) {
   case 0:  oprintf(UPO, "ack %s ok\n", ci->name);                    break;
@@ -227,14 +229,15 @@ static void obc_error(OutBufferChain *ch, const char *e1, const char *e2) {
   exit(-1);
 }
 
-void ouhex(const char *word, const Byte *command, int length) {
+void ouhexo(const char *word, const Byte *command, int length) {
   oprintf(UPO, "%s", word);
-  while (length) {
-    oprintf(UPO, " %02x", *command++);
-    length--;
-  }
+  while (length--) oprintf(UPO, " %02x", *command++);
   oprintf(UPO, "\n");
 }
+void ouhexi(const char *word, const Byte *command, int length) {
+  simlog_serial(command,length);
+  ouhexo(word,command,length);
+}
  
 void die_vprintf_hook(const char *fmt, va_list al) {
   if (events) ovprintf(UPO, fmt, al);
@@ -317,7 +320,7 @@ void serial_transmit(const PicInsn *pi) {
   }
 
   if (!suppress && picio_send_noise >= 2)
-    ouhex("picioh out", pi->d, pi->l);
+    ouhexo("picioh out", pi->d, pi->l);
 
   /* note that the serial port is still in nonblocking mode.  if
    * we ever buffer up far enough that the kernel wants to make us
@@ -359,11 +362,7 @@ int main(int argc, const char **argv) {
     sys_events= oop_sys_new();  if (!sys_events) diee("oop_sys_new");
     events= oop_sys_source(sys_events);  massert(events);
 
-    if (logcopy_fn[0] && strcmp(logcopy_fn,"-")) {
-      cmdi.out.logcopy= fopen(logcopy_fn,"w");
-      if (!cmdi.out.logcopy) diee("open log copy %s",logcopy_fn);
-    }
-
+    simlog_open(logcopy_fn);
     cmdin_new(&cmdi, 0);
 
     serial_open(device);
@@ -373,7 +372,7 @@ int main(int argc, const char **argv) {
     events->on_fd(events, serial_fd, OOP_EXCEPTION, read_exception, 0);
 
   } else {
-    sim_initialise();
+    sim_initialise(logcopy_fn);
     sys_events= 0;
   }
 

diff --git a/hostside/realtime.h b/hostside/realtime.h
index 06b04463c73697db6a14618a435e0b9c25a4aa66..a261eea3f4d064751b6e72edfd1af26164d7b534 100644 (file)
--- a/hostside/realtime.h
+++ b/hostside/realtime.h
@@ -145,7 +145,8 @@ void persist_map_veryearly(void);
 /*---------- from/for realtime.c ----------*/
 
 void oupicio(const char *dirn, const PicInsnInfo *pii, int objnum);
-void ouhex(const char *word, const Byte *command, int length);
+void ouhexi(const char *word, const Byte *command, int length);
+void ouhexo(const char *word, const Byte *command, int length);
 
 void serial_transmit(const PicInsn *pi);
 
@@ -154,9 +155,15 @@ void serial_transmit(const PicInsn *pi);
 const char *simulate;
 void serial_indata_process(int buf_used);
 
-void sim_initialise(void);
+void sim_initialise(const char *logduplicate);
 void sim_run(void);
 
+void simlogv(const char *fmt, va_list al);
+void simlog(const char *fmt, ...);
+void simlog_serial(const Byte *data, int length);
+void simlog_flush(void);
+void simlog_open(const char *fn);
+
 void mgettimeofday(struct timeval *tv); /* contains magic for simulation */
 void *toev_callback(oop_source *source, struct timeval tv, void *t_v);
 

diff --git a/hostside/simulate.c b/hostside/simulate.c
index 801b06580697db9876f3465c04adf315142a22f7..f0b8f7e4e4f57bbaa507ca1b94d8e2d274e4b7c3 100644 (file)
--- a/hostside/simulate.c
+++ b/hostside/simulate.c
@@ -17,19 +17,56 @@ static SimEventFn se_serial, se_command, se_eof;
 
 static SimTimeout *simtimeouts;
 
+static FILE *simoutput;
 static FILE *siminput;
 static char *sevent_buf;
 static size_t sevent_buflen;
+static int sevent_lno;
 
 static SimEventFn *sevent_type;
 static char *sevent_data;
 static struct timeval sevent_abst;
 
+/*---------- writing simulation log ----------*/
+
+void simlogv(const char *fmt, va_list al) {
+  if (simoutput==stdout) ovprintf(UPO,fmt,al);
+  else if (simoutput) vfprintf(simoutput,fmt,al);
+}
+void simlog(const char *fmt, ...) {
+  va_list al;
+  va_start(al,fmt);
+  simlogv(fmt,al);
+  va_end(al);
+}
+void simlog_flush(void) {
+  if (simoutput==stdout) obc_tryflush(UPO);
+  else if (simoutput)
+    if (ferror(simoutput) || fflush(simoutput))
+      diee("write simulation log");
+}
+void simlog_serial(const Byte *data, int length) {
+  simlog("picioh in suppressed");
+  while (length--) simlog(" %02x",*data++);
+  simlog("\n");
+  simlog_flush();
+}
+void simlog_open(const char *fn) {
+  if (!fn) fn= "+realtime.log";
+  if (!strcmp(fn,"-")) {
+    simoutput= stdout; /* we don't really use this - see vsimlog */
+  } else if (fn[0]) {
+    simoutput= fopen(fn,"w");
+    if (!simoutput) diee("open simulation log %s",fn);
+    cmdi.out.logcopy= simoutput;
+  }
+}
+
 /*---------- simulation input stream parser ----------*/
 
 static void simbad(const char *how) __attribute__((noreturn));
 static void simbad(const char *how) {
-  die("bad simulation (in `%s'): %s", sevent_buf, how);
+  die("simulation failed (line %d, in `%s'): %s", sevent_lno, sevent_buf, how);
 }
 
 static void sevent(void) {
@@ -40,18 +77,20 @@ static void sevent(void) {
     return;
 
   for (;;) {
+    sevent_lno++;
+
     gr= getline(&sevent_buf,&sevent_buflen,siminput);
     if (feof(siminput)) { sevent_type= se_eof; return; }
     if (ferror(siminput)) diee("read simulation input failed");
     assert(gr>0);
     assert(sevent_buf[gr-1]=='\n');
     sevent_buf[gr-1]= 0;
-    
+
 #define IF_ET(pfx, et)                                                 \
     if (!strncmp(pfx " ", sevent_buf, sizeof(pfx))                     \
        && (sevent_type=(et), p=sevent_buf+(sizeof(pfx))))
 
-    IF_ET("executing", se_command) {
+    IF_ET("command-in", se_command) {
       sevent_data= p;
       return;
     }
@@ -99,6 +138,9 @@ void sim_mgettimeofday(struct timeval *tv) {
   *tv= sevent_abst;
   if (sevent_type==se_timestamp)
     sevent_type= 0;
+  else
+    fprintf(stderr,"simulation warning -"
+           " mgettimeofday desynched at line %d\n", sevent_lno);
 }
 
 /*---------- simulation events ----------*/
@@ -162,20 +204,24 @@ static void se_eof(void) {
 
 /*---------- core ----------*/
 
-void sim_initialise(void) {
+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");
   siminput= fopen(simulate,"r");
   if (!siminput) diee("open simulation input %s",simulate);
+  if (logduplicate)
+    simlog_open(logduplicate);
 }
 
 void sim_run(void) {
+  SimEventFn *fn;
   for (;;) {
     sevent();
-    sevent_type();
+    fn= sevent_type;
     sevent_type= 0;
+    fn();
     obc_tryflush(&cmdi.out);
   }
 }

diff --git a/hostside/startup.c b/hostside/startup.c
index 1a9c6802e61d3f17c14ffca6929f22877f5e7213..416340bdbe071cba7d0d188396d146476b767ec5 100644 (file)
--- a/hostside/startup.c
+++ b/hostside/startup.c
@@ -40,6 +40,7 @@ static void initial_ping(void) {
   struct timeval now;
   
   mgettimeofday(&now);
+oprintf(DUPO("ip") " %ld.%06ld\n", now.tv_sec, now.tv_usec);
   ping_seq= (now.tv_sec & 0x1fU) << 5; /* bottom 5bi of secs: period 32s */
   ping_seq |= (now.tv_usec >> 15);      /* top 5bi of 20bi us: res.~2^15us */
   ping_toev.duration=  300;
@@ -130,21 +131,21 @@ void serial_moredata(PicInsn *buf) {
   
   if (sta_state == Sta_Flush) {
     toev_start(&sta_toev);
-    ouhex("picioh in junk", buf->d, buf->l);
+    ouhexi("picioh in junk", buf->d, buf->l);
     return; /* junk absolutely everything */
   }
   if (PICMSG_AAARGH_P(buf->d[0])) {
-    ouhex("picioh in aaargh", buf->d, buf->l);
+    ouhexi("picioh in aaargh", buf->d, buf->l);
     die("PIC sent us AAARGH!");
   }
   if (PICMSG_HELLO_P(buf->d[0])) {
-    ouhex("picioh in hello", buf->d, 1);
+    ouhexi("picioh in hello", buf->d, 1);
     sta_goto(Sta_Flush);
     buf->l= 1;
     return;
   }
   if (sta_state == Sta_Off) {
-    ouhex("picioh in off", buf->d, 1);
+    ouhexi("picioh in off", buf->d, 1);
     buf->l= 1;
     return;
   }
@@ -157,7 +158,7 @@ void serial_moredata(PicInsn *buf) {
       goto found_end;
 
   if (buf->l == sizeof(buf->d)) {
-    ouhex("picioh in toolong", buf->d, buf->l);
+    ouhexi("picioh in toolong", buf->d, buf->l);
     die("PIC sent packet too long");
   }
   buf->l= 0; /* message not yet finished, so consume nothing */
@@ -168,8 +169,12 @@ void serial_moredata(PicInsn *buf) {
   buf->l= ep - buf->d + 1;
   picinsn_decode(buf, pic_reply_infos, &pii, &objnum);
   suppress= pii && pii->noiselevel > picio_send_noise;
+
   if (!suppress && picio_send_noise >= 2)
-    ouhex("picioh in msg", buf->d, buf->l);
+    ouhexi("picioh in msg", buf->d, buf->l);
+  else
+    simlog_serial(buf->d, buf->l);
+  
   if (!pii) { oprintf(UPO, "picio in unknown\n"); return; }
   if (!suppress)
     oupicio("in",pii,objnum);

diff --git a/hostside/x.gdb b/hostside/x.gdb
index 6e0c285159ec310bb31fc14bcc3160b3edc6c8a2..3fb0e8c777f47b1868e155dea30e718fb4ca4b2f 100644 (file)
--- a/hostside/x.gdb
+++ b/hostside/x.gdb
@@ -9,6 +9,8 @@ break nmra_errchk_fail
 break predict_problem
 break safety_panic
 
+#break real_mgettimeofday
+
 run
 
 # valgrind  ./realtime shinkansen.speeds.record homes.record

diff --git a/hostside/xs.gdb b/hostside/xs.gdb
index db251a435406dd955834970262bbddc55a0e2247..e9564fdd4915a0e15e3973242935d4ca0d63037d 100644 (file)
--- a/hostside/xs.gdb
+++ b/hostside/xs.gdb
@@ -3,5 +3,6 @@ break vdie
 break nmra_errchk_fail
 break predict_problem
 break safety_panic
+#break mgettimeofday
 set args -S+realtime.log shinkansen.speeds.record homes.record 
 run