Cleaned up messages emitted by klee-replay, and prefixed them all with "KLEE-REPLAY:" to distinguish them from those printed by the replayed program

2 files changed, 57 insertions, 61 deletions

diff --git a/tools/klee-replay/file-creator.c b/tools/klee-replay/file-creator.c
index 58580f94..6440b414 100644
--- a/tools/klee-replay/file-creator.c
+++ b/tools/klee-replay/file-creator.c
@@ -90,7 +90,7 @@ int wait_for_timeout_or_exit(pid_t pid, const char *name, int *statusp) {
   int timeout = t ? atoi(t) : 5;
   double wait = timeout * .5;
   double start = getTime();
-  fprintf(stderr, "note: %s: waiting %.2fs\n", name, wait);
+  fprintf(stderr, "KLEE-REPLAY: NOTE: %s: waiting %.2fs\n", name, wait);
   while (getTime() - start < wait) {
     struct timespec r = {0, 1000000};
     nanosleep(&r, 0);
@@ -150,7 +150,7 @@ static int create_char_dev(const char *fname, exe_disk_file_t *dfile,
     }
 
     if (symlink(name, fname) == -1) {
-      fprintf(stderr, "unable to create sym link to tty\n");
+      fprintf(stderr, "KLEE-REPLAY: ERROR: unable to create sym link to tty\n");
       perror("symlink");
     }
 
@@ -164,7 +164,7 @@ static int create_char_dev(const char *fname, exe_disk_file_t *dfile,
     } else if (pid == 0) {
       close(amaster);
 
-      fprintf(stderr, "note: pty slave: setting raw mode\n");
+      fprintf(stderr, "KLEE-REPLAY: NOTE: pty slave: setting raw mode\n");
       {
         struct termios mode;
 
@@ -187,19 +187,19 @@ static int create_char_dev(const char *fname, exe_disk_file_t *dfile,
     } else {
       unsigned pos = 0;
       int status;
-      fprintf(stderr, "note: pty master: starting\n");
+      fprintf(stderr, "KLEE-REPLAY: NOTE: pty master: starting\n");
       close(aslave);
 
       while (pos < flen) {
         ssize_t res = write(amaster, &contents[pos], flen - pos);
         if (res<0) {
           if (errno != EINTR) {
-            fprintf(stderr, "note: pty master: write error\n");
+            fprintf(stderr, "KLEE-REPLAY: NOTE: pty master: write error\n");
             perror("errno");
             break;
           }
         } else if (res) {
-          fprintf(stderr, "note: pty master: wrote: %zd (of %d)\n", res, flen);
+          fprintf(stderr, "KLEE-REPLAY: NOTE: pty master: wrote: %zd (of %d)\n", res, flen);
           pos += res;
         }
       }
@@ -207,7 +207,7 @@ static int create_char_dev(const char *fname, exe_disk_file_t *dfile,
       if (wait_for_timeout_or_exit(pid, "pty master", &status))
         goto pty_exit;
 
-      fprintf(stderr, "note: pty master: closing & waiting\n");
+      fprintf(stderr, "KLEE-REPLAY: NOTE: pty master: closing & waiting\n");
       close(amaster);
       while (1) {
         pid_t res = waitpid(pid, &status, 0);
@@ -221,7 +221,7 @@ static int create_char_dev(const char *fname, exe_disk_file_t *dfile,
 
     pty_exit:
       close(amaster);
-      fprintf(stderr, "note: pty master: done\n");
+      fprintf(stderr, "KLEE-REPLAY: NOTE: pty master: done\n");
       process_status(status, 0, "PTY MASTER");
     }
   }
@@ -252,7 +252,7 @@ static int create_pipe(const char *fname, exe_disk_file_t *dfile,
   } else {
     unsigned pos = 0;
     int status;
-    fprintf(stderr, "note: pipe master: starting\n");
+    fprintf(stderr, "KLEE-REPLAY: NOTE: pipe master: starting\n");
     close(fds[0]);
 
     while (pos < flen) {
@@ -268,7 +268,7 @@ static int create_pipe(const char *fname, exe_disk_file_t *dfile,
     if (wait_for_timeout_or_exit(pid, "pipe master", &status))
       goto pipe_exit;
 
-    fprintf(stderr, "note: pipe master: closing & waiting\n");
+    fprintf(stderr, "KLEE-REPLAY: NOTE: pipe master: closing & waiting\n");
     close(fds[1]);
     while (1) {
       pid_t res = waitpid(pid, &status, 0);
@@ -282,7 +282,7 @@ static int create_pipe(const char *fname, exe_disk_file_t *dfile,
 
   pipe_exit:
     close(fds[1]);
-    fprintf(stderr, "note: pipe master: done\n");
+    fprintf(stderr, "KLEE-REPLAY: NOTE: pipe master: done\n");
     process_status(status, 0, "PTY MASTER");
   }
 }
@@ -295,23 +295,20 @@ static int create_reg_file(const char *fname, exe_disk_file_t *dfile,
   unsigned flen = dfile->size;
   unsigned mode = s->st_mode & 0777;
 
-  //fprintf(stderr, "Creating regular file\n");
-
   // Open in RDWR just in case we have to end up using this fd.
-
   if (__exe_env.version == 0 && mode == 0)
     mode = 0644;
 
   int fd = open(fname, O_CREAT | O_RDWR, mode);
   //    int fd = open(fname, O_CREAT | O_WRONLY, s->st_mode&0777);
   if (fd < 0) {
-    fprintf(stderr, "Cannot create file %s\n", fname);
+    fprintf(stderr, "KLEE-REPLAY: ERROR: Cannot create file %s\n", fname);
     exit(1);
   }
 
   ssize_t r = write(fd, contents, flen);
   if (r < 0 || (unsigned) r != flen) {
-    fprintf(stderr, "Cannot write file %s\n", fname);
+    fprintf(stderr, "KLEE-REPLAY: ERROR: Cannot write file %s\n", fname);
     exit(1);
   }
 
@@ -348,7 +345,7 @@ static int delete_dir(const char *path, int recurse) {
   }
 
   if (rmdir(path) == -1) {
-    fprintf(stderr, "Cannot create file %s (exists, is dir, can't remove)\n", path);
+    fprintf(stderr, "KLEE-REPLAY: ERROR: Cannot create file %s (exists, is dir, can't remove)\n", path);
     perror("rmdir");
     return -1;
   }
@@ -361,7 +358,7 @@ static void delete_file(const char *path, int recurse) {
     if (errno == EISDIR) {
       delete_dir(path, 1);
     } else {
-      fprintf(stderr, "Cannot create file %s (already exists)\n", path);
+      fprintf(stderr, "KLEE-REPLAY: ERROR: Cannot create file %s (already exists)\n", path);
       perror("unlink");
     }
   }
@@ -412,7 +409,7 @@ static void create_file(int target_fd,
     if (target_fd != -1) {
       close(target_fd);
       if (dup2(fd, target_fd) < 0) {
-        fprintf(stderr, "note: dup2 failed for target: %d\n", target_fd);
+        fprintf(stderr, "KLEE-REPLAY: ERROR: dup2 failed for target: %d\n", target_fd);
         perror("dup2");
       }
       close(fd);
@@ -446,7 +443,7 @@ void replay_create_files(exe_file_system_t *exe_fs) {
     exit(EXIT_FAILURE);
   }
 
-  fprintf(stderr, "note: storing KLEE replay files in %s\n", tmpdir);
+  fprintf(stderr, "KLEE-REPLAY: NOTE: Storing KLEE replay files in %s\n", tmpdir);
 
   umask(0);
   for (k=0; k < exe_fs->n_sym_files; k++) {
@@ -481,7 +478,7 @@ int remove_callback(const char *fpath,
 }
 
 void replay_delete_files() {
-  fprintf(stderr, "removing %s\n", replay_dir);
+  fprintf(stderr, "KLEE-REPLAY: NOTE: removing %s\n", replay_dir);
 
   if (nftw(replay_dir, remove_callback, FOPEN_MAX,
            FTW_DEPTH | FTW_PHYS) == -1) {
@@ -512,60 +509,60 @@ static void check_file(int index, exe_disk_file_t *dfile) {
   }
 
   if (res < 0) {
-    fprintf(stderr, "warning: check_file %d: stat failure\n", index);
+    fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %d: stat failure\n", index);
     return;
   }
 
   if (s.st_dev != dfile->stat->st_dev) {
-    fprintf(stderr, "warning: check_file %s: dev mismatch: %d vs %d\n",
+    fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: dev mismatch: %d vs %d\n",
             name, (int) s.st_dev, (int) dfile->stat->st_dev);
   }
 /*   if (s.st_ino != dfile->stat->st_ino) { */
-/*     fprintf(stderr, "warning: check_file %s: ino mismatch: %d vs %d\n",  */
+/*     fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: ino mismatch: %d vs %d\n",  */
 /*             name, (int) s.st_ino, (int) dfile->stat->st_ino);     */
 /*   } */
   if (s.st_mode != dfile->stat->st_mode) {
-    fprintf(stderr, "warning: check_file %s: mode mismatch: %#o vs %#o\n",
+    fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: mode mismatch: %#o vs %#o\n",
             name, s.st_mode, dfile->stat->st_mode);
   }
   if (s.st_nlink != dfile->stat->st_nlink) {
-    fprintf(stderr, "warning: check_file %s: nlink mismatch: %d vs %d\n",
+    fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: nlink mismatch: %d vs %d\n",
             name, (int) s.st_nlink, (int) dfile->stat->st_nlink);
   }
   if (s.st_uid != dfile->stat->st_uid) {
-    fprintf(stderr, "warning: check_file %s: uid mismatch: %d vs %d\n",
+    fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: uid mismatch: %d vs %d\n",
             name, s.st_uid, dfile->stat->st_uid);
   }
   if (s.st_gid != dfile->stat->st_gid) {
-    fprintf(stderr, "warning: check_file %s: gid mismatch: %d vs %d\n",
+    fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: gid mismatch: %d vs %d\n",
             name, s.st_gid, dfile->stat->st_gid);
   }
   if (s.st_rdev != dfile->stat->st_rdev) {
-    fprintf(stderr, "warning: check_file %s: rdev mismatch: %d vs %d\n",
+    fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: rdev mismatch: %d vs %d\n",
             name, (int) s.st_rdev, (int) dfile->stat->st_rdev);
   }
   if (s.st_size != dfile->stat->st_size) {
-    fprintf(stderr, "warning: check_file %s: size mismatch: %d vs %d\n",
+    fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: size mismatch: %d vs %d\n",
             name, (int) s.st_size, (int) dfile->stat->st_size);
   }
   if (s.st_blksize != dfile->stat->st_blksize) {
-    fprintf(stderr, "warning: check_file %s: blksize mismatch: %d vs %d\n",
+    fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: blksize mismatch: %d vs %d\n",
             name, (int) s.st_blksize, (int) dfile->stat->st_blksize);
   }
   if (s.st_blocks != dfile->stat->st_blocks) {
-    fprintf(stderr, "warning: check_file %s: blocks mismatch: %d vs %d\n",
+    fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: blocks mismatch: %d vs %d\n",
             name, (int) s.st_blocks, (int) dfile->stat->st_blocks);
   }
 /*   if (s.st_atime != dfile->stat->st_atime) { */
-/*     fprintf(stderr, "warning: check_file %s: atime mismatch: %d vs %d\n",  */
+/*     fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: atime mismatch: %d vs %d\n",  */
 /*             name, (int) s.st_atime, (int) dfile->stat->st_atime); */
 /*   } */
 /*   if (s.st_mtime != dfile->stat->st_mtime) { */
-/*     fprintf(stderr, "warning: check_file %s: mtime mismatch: %d vs %d\n",  */
+/*     fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: mtime mismatch: %d vs %d\n",  */
 /*             name, (int) s.st_mtime, (int) dfile->stat->st_mtime);     */
 /*   } */
 /*   if (s.st_ctime != dfile->stat->st_ctime) { */
-/*     fprintf(stderr, "warning: check_file %s: ctime mismatch: %d vs %d\n",  */
+/*     fprintf(stderr, "KLEE-REPLAY: WARNING: check_file %s: ctime mismatch: %d vs %d\n",  */
 /*             name, (int) s.st_ctime, (int) dfile->stat->st_ctime);     */
 /*   } */
 }
diff --git a/tools/klee-replay/klee-replay.c b/tools/klee-replay/klee-replay.c
index 1399985d..9f5acef8 100644
--- a/tools/klee-replay/klee-replay.c
+++ b/tools/klee-replay/klee-replay.c
@@ -52,10 +52,10 @@ static struct option long_options[] = {
 };
 
 static void stop_monitored(int process) {
-  fprintf(stderr, "TIMEOUT: ATTEMPTING GDB EXIT\n");
+  fprintf(stderr, "KLEE-REPLAY: NOTE: TIMEOUT: ATTEMPTING GDB EXIT\n");
   int pid = fork();
   if (pid < 0) {
-    fprintf(stderr, "ERROR: gdb_exit: fork failed\n");
+    fprintf(stderr, "KLEE-REPLAY: ERROR: gdb_exit: fork failed\n");
   } else if (pid == 0) {
     /* Run gdb in a child process. */
     const char *gdbargs[] = {
@@ -74,7 +74,7 @@ static void stop_monitored(int process) {
     /* Make sure gdb doesn't talk to the user */
     close(0);
 
-    fprintf(stderr, "RUNNING GDB: ");
+    fprintf(stderr, "KLEE-REPLAY: NOTE: RUNNING GDB: ");
     unsigned i;
     for (i = 0; i != 5; ++i)
       fprintf(stderr, "%s ", gdbargs[i]);
@@ -98,7 +98,7 @@ static void stop_monitored(int process) {
 }
 
 static void int_handler(int signal) {
-  fprintf(stderr, "%s: Received signal %d.  Killing monitored process(es)\n",
+  fprintf(stderr, "KLEE-REPLAY: NOTE: %s: Received signal %d.  Killing monitored process(es)\n",
           progname, signal);
   if (monitored_pid) {
     stop_monitored(monitored_pid);
@@ -111,7 +111,7 @@ static void int_handler(int signal) {
   }
 }
 static void timeout_handler(int signal) {
-  fprintf(stderr, "%s: EXIT STATUS: TIMED OUT (%d seconds)\n", progname,
+  fprintf(stderr, "KLEE-REPLAY: NOTE: EXIT STATUS: TIMED OUT (%d seconds)\n",
           monitored_timeout);
   if (monitored_pid) {
     stop_monitored(monitored_pid);
@@ -125,11 +125,10 @@ static void timeout_handler(int signal) {
 }
 
 void process_status(int status, time_t elapsed, const char *pfx) {
-  fprintf(stderr, "%s: ", progname);
   if (pfx)
-    fprintf(stderr, "%s: ", pfx);
+    fprintf(stderr, "KLEE-REPLAY: NOTE: %s: ", pfx);
   if (WIFSIGNALED(status)) {
-    fprintf(stderr, "EXIT STATUS: CRASHED signal %d (%d seconds)\n",
+    fprintf(stderr, "KLEE-REPLAY: NOTE: EXIT STATUS: CRASHED signal %d (%d seconds)\n",
             WTERMSIG(status), (int) elapsed);
     _exit(77);
   } else if (WIFEXITED(status)) {
@@ -141,10 +140,10 @@ void process_status(int status, time_t elapsed, const char *pfx) {
     } else {
       sprintf(msg, "ABNORMAL %d", rc);
     }
-    fprintf(stderr, "EXIT STATUS: %s (%d seconds)\n", msg, (int) elapsed);
+    fprintf(stderr, "KLEE-REPLAY: NOTE: EXIT STATUS: %s (%d seconds)\n", msg, (int) elapsed);
     _exit(rc);
   } else {
-    fprintf(stderr, "EXIT STATUS: NONE (%d seconds)\n", (int) elapsed);
+    fprintf(stderr, "KLEE-REPLAY: NOTE: EXIT STATUS: NONE (%d seconds)\n", (int) elapsed);
     _exit(0);
   }
 }
@@ -164,7 +163,7 @@ static void run_monitored(char *executable, int argc, char **argv) {
   monitored_timeout = atoi(t);
 
   if (monitored_timeout==0) {
-    fprintf(stderr, "ERROR: invalid timeout (%s)\n", t);
+    fprintf(stderr, "KLEE-REPLAY: ERROR: invalid timeout (%s)\n", t);
     _exit(1);
   }
 
@@ -196,7 +195,7 @@ static void run_monitored(char *executable, int argc, char **argv) {
       _exit(66);
     }
 
-    fprintf(stderr, "rootdir: %s\n", rootdir);
+    fprintf(stderr, "KLEE-REPLAY: NOTE: rootdir: %s\n", rootdir);
     const char *msg;
     if ((msg = "chdir", chdir(rootdir) == 0) &&
       (msg = "chroot", chroot(rootdir) == 0)) {
@@ -246,7 +245,7 @@ void ensure_capsyschroot(const char *executable) {
   cap_get_flag(caps, CAP_SYS_CHROOT, CAP_PERMITTED, &chroot_permitted);
   cap_get_flag(caps, CAP_SYS_CHROOT, CAP_EFFECTIVE, &chroot_effective);
   if (chroot_permitted != CAP_SET || chroot_effective != CAP_SET) {
-    fprintf(stderr, "Error: chroot: No CAP_SYS_CHROOT capability.\n");
+    fprintf(stderr, "KLEE-REPLAY: ERROR: chroot: No CAP_SYS_CHROOT capability.\n");
     exit(1);
   }
   cap_free(caps);
@@ -287,7 +286,7 @@ int main(int argc, char** argv) {
 
         input = kTest_fromFile(input_fname);
         if (!input) {
-          fprintf(stderr, "%s: error: input file %s not valid.\n", progname,
+          fprintf(stderr, "KLEE-REPLAY: ERROR: input file %s not valid.\n",
                   input_fname);
           exit(1);
         }
@@ -318,14 +317,14 @@ int main(int argc, char** argv) {
 
   /* rootdir should be a prefix of executable's path. */
   if (rootdir && strstr(executable, rootdir) != executable) {
-    fprintf(stderr, "Error: chroot: root dir should be a parent dir of executable.\n");
+    fprintf(stderr, "KLEE-REPLAY: ERROR: chroot: root dir should be a parent dir of executable.\n");
     exit(1);
   }
 
   /* Verify the executable exists. */
   FILE *f = fopen(executable, "r");
   if (!f) {
-    fprintf(stderr, "Error: executable %s not found.\n", executable);
+    fprintf(stderr, "KLEE-REPLAY: ERROR: executable %s not found.\n", executable);
     exit(1);
   }
   fclose(f);
@@ -337,7 +336,7 @@ int main(int argc, char** argv) {
 
     input = kTest_fromFile(input_fname);
     if (!input) {
-      fprintf(stderr, "%s: error: input file %s not valid.\n", progname,
+      fprintf(stderr, "KLEE-REPLAY: ERROR: input file %s not valid.\n",
               input_fname);
       exit(1);
     }
@@ -349,8 +348,8 @@ int main(int argc, char** argv) {
     klee_init_env(&prg_argc, &prg_argv);
     if (idx > 2)
       fprintf(stderr, "\n");
-    fprintf(stderr, "%s: TEST CASE: %s\n", progname, input_fname);
-    fprintf(stderr, "%s: ARGS: ", progname);
+    fprintf(stderr, "KLEE-REPLAY: NOTE: Test file: %s\n", input_fname);
+    fprintf(stderr, "KLEE-REPLAY: NOTE: Arguments: ");
     for (i=0; i != (unsigned) prg_argc; ++i) {
       char *s = prg_argv[i];
       if (s[0]=='A' && s[1] && !s[2]) s[1] = '\0';
@@ -409,16 +408,16 @@ int klee_get_errno() {
 }
 
 void klee_warning(char *name) {
-  fprintf(stderr, "WARNING: %s\n", name);
+  fprintf(stderr, "KLEE-REPLAY: klee_warning: %s\n", name);
 }
 
 void klee_warning_once(char *name) {
-  fprintf(stderr, "WARNING: %s\n", name);
+  fprintf(stderr, "KLEE-REPLAY: klee_warning_once: %s\n", name);
 }
 
 unsigned klee_assume(uintptr_t x) {
   if (!x) {
-    fprintf(stderr, "WARNING: klee_assume(0)!\n");
+    fprintf(stderr, "KLEE-REPLAY: klee_assume(0)!\n");
   }
   return 0;
 }
@@ -453,7 +452,7 @@ void klee_make_symbolic(void *addr, size_t nbytes, const char *name) {
       *((int*) addr) = 0;
     } else {
       if (boo->numBytes != nbytes) {
-        fprintf(stderr, "make_symbolic mismatch, different sizes: "
+        fprintf(stderr, "KLEE-REPLAY: ERROR: make_symbolic mismatch, different sizes: "
            "%d in input file, %lu in code\n", boo->numBytes, (unsigned long)nbytes);
         exit(1);
       } else {
@@ -469,7 +468,7 @@ int klee_range(int start, int end, const char* name) {
   int r;
 
   if (start >= end) {
-    fprintf(stderr, "klee_range: invalid range\n");
+    fprintf(stderr, "KLEE-REPLAY: ERROR: klee_range: invalid range\n");
     exit(1);
   }
 
@@ -479,7 +478,7 @@ int klee_range(int start, int end, const char* name) {
     klee_make_symbolic(&r, sizeof r, name);
 
     if (r < start || r >= end) {
-      fprintf(stderr, "klee_range(%d, %d, %s) returned invalid result: %d\n",
+      fprintf(stderr, "KLEE-REPLAY: ERROR: klee_range(%d, %d, %s) returned invalid result: %d\n",
         start, end, name, r);
       exit(1);
     }
@@ -500,6 +499,6 @@ void klee_mark_global(void *object) {
 /*** HELPER FUNCTIONS ***/
 
 static void __emit_error(const char *msg) {
-  fprintf(stderr, "ERROR: %s\n", msg);
+  fprintf(stderr, "KLEE-REPLAY: ERROR: %s\n", msg);
   exit(1);
 }