Quiet enigmas printing (#1786)

Redirect the majority of debug printing to log files to make the CI output easier to navigate (and give users a convenient log file to upload in the event that something goes wrong).

Logging practices are a little rough around the edges, but good enough for now.

.gitignore

@@ -10,7 +10,6 @@
 /libEGM.*
 /libProtocols.*
 
-
 /shared/protos/build/
 /shared/protos/codegen
 /CommandLine/libEGM/build/

.travis.yml

@@ -205,4 +205,5 @@ script:
       ./ci-regression.sh "/tmp/enigma-master" 4 || travis_terminate $?
     else
       ./ci-build.sh
+      ./share_logs.sh
     fi

CommandLine/emake/Main.cpp

@@ -20,9 +20,11 @@
 #include <fstream>
 #include <iostream>
 #include <streambuf>
+#include <cstdlib>
 
-std::ostream outputStream(std::cout.rdbuf());
-std::ostream errorStream(std::cerr.rdbuf());
+std::ostream outputStream(nullptr);
+std::ostream errorStream(nullptr);
+std::ofstream egmlog("logs/enigma_libegm.log", std::ofstream::out);
 
 static std::string tolower(const std::string &str) {
   std::string res = str;
@@ -34,6 +36,17 @@ static std::string tolower(const std::string &str) {
 
 int main(int argc, char* argv[])
 {
+  std::string ENIGMA_DEBUG = (std::getenv("ENIGMA_DEBUG") ? std::getenv("ENIGMA_DEBUG") : "");
+  if (ENIGMA_DEBUG == "TRUE") {
+    outputStream.rdbuf(std::cout.rdbuf());
+    errorStream.rdbuf(std::cerr.rdbuf());
+  } else {
+    outputStream.rdbuf(egmlog.rdbuf());
+    errorStream.rdbuf(egmlog.rdbuf());
+    std::cout << "LibEGM parsing log at: logs/enigma_libegm.log" << std::endl;
+  }
+
+
   OptionsParser options;
   options.ReadArgs(argc, argv);
   int result = options.HandleArgs();

CommandLine/testing/Platform/TestHarness-X11.cpp

@@ -161,7 +161,9 @@ int build_game(const string &game, const TestConfig &tc, const string &out) {
   if (pid_t emake = fork()) {
     int status = 0;
     if (emake == -1) return -1;
-    if (waitpid(emake, &status, 0) == -1) return -1;
+    int ret = (waitpid(emake, &status, 0) == -1);
+    system("./share_logs.sh");
+    if (ret) return -1;
     if (WIFEXITED(status)) return WEXITSTATUS(status);
     return -1;
   }

CompilerSource/JDI/src/API/error_reporting.cpp

@@ -19,30 +19,33 @@
  * JustDefineIt. If not, see <http://www.gnu.org/licenses/>.
 **/
 
-#include <cstdio>
+#include <iostream>
 #include <API/error_reporting.h>
 
+using std::cout;
+using std::endl;
+
 namespace jdi {
   void default_error_handler::error(std::string err, std::string filename, int line, int pos) {
     if (!filename.length())
-      fprintf(stderr, "ERROR: %s\n", err.c_str());
+      cout <<  "ERROR: " << err << endl;
     if (line == -1)
-      fprintf(stderr, "ERROR(%s): %s\n", filename.c_str(), err.c_str());
+      cout <<  "ERROR(" << filename << "): " << err << endl;
     else if (pos == -1)
-      fprintf(stderr, "ERROR(%s:%d): %s\n", filename.c_str(), line, err.c_str());
+      cout <<  "ERROR(" << filename << ":" << line <<  "): " << err << endl;
     else
-      fprintf(stderr, "ERROR(%s,%d,%d): %s\n", filename.c_str(), line, pos, err.c_str());
+      cout <<  "ERROR(" << filename << "," << line << "," << pos << "): " << err << endl;
     ++error_count;
   }
   void default_error_handler::warning(std::string err, std::string filename, int line, int pos) {
     if (!filename.length())
-      fprintf(stderr, "Warning: %s\n", err.c_str());
+      cout <<  "WARNING: " << err << endl;
     if (line == -1)
-      fprintf(stderr, "Warning(%s): %s\n", filename.c_str(), err.c_str());
+      cout <<  "WARNING(" << filename << "): " << err << endl;
     else if (pos == -1)
-      fprintf(stderr, "Warning(%s:%d): %s\n", filename.c_str(), line, err.c_str());
+      cout <<  "WARNING(" << filename << ":" << line <<  "): " << err << endl;
     else
-      fprintf(stderr, "Warning(%s,%d,%d): %s\n", filename.c_str(), line, pos, err.c_str());
+      cout <<  "WARNING(" << filename << "," << line <<  "," << pos << "): " << err << endl;
     ++warning_count;
   }
 

CompilerSource/backend/ideprint.cpp

@@ -21,15 +21,17 @@
 
 ideprint::ideprint(void(*ftu)(const char*)): f(ftu) {}
 
-#include <stdio.h>
+#include <iostream>
+
+extern std::ostream realCout;
 
 // Now specialize it 
 // Declare functions it'll call
 void ide_dia_add_direct(const char* x) {
-  printf("%s",x); fflush(stdout); ide_dia_add(x);
+  realCout << x; std::cout << x; fflush(stdout); ide_dia_add(x);
 }
 void ide_dia_add_debug(const char* x) {
-  printf("%s",x); fflush(stdout); ide_dia_add(x);
+  realCout << x; std::cout << x; fflush(stdout); ide_dia_add(x);
 }
 // Link them together
 ideprint user(ide_dia_add_direct);

CompilerSource/general/bettersystem.cpp

@@ -28,7 +28,7 @@
 #include <string>
 #include <cstdlib>
 #include <cstring>
-#include <cstdio>
+#include <iostream>
 
 using namespace std;
 
@@ -179,14 +179,14 @@ void myReplace(std::string& str, const std::string& oldStr, const std::string& n
           if (!StartupInfo.hStdInput or StartupInfo.hStdInput == INVALID_HANDLE_VALUE)
           {
             HANDLE conin = CreateFile("CONIN$", GENERIC_READ | GENERIC_WRITE, FILE_SHARE_READ | FILE_SHARE_WRITE, FALSE, OPEN_EXISTING, 0, NULL);
-              if (!conin || conin == INVALID_HANDLE_VALUE) { printf("CreateFile(CONIN$) failed (Error%d)\n", (int)GetLastError()); }
+              if (!conin || conin == INVALID_HANDLE_VALUE) { cerr << "CreateFile(CONIN$) failed (Error" << (int)GetLastError() << ")" << std::endl; }
             StartupInfo.hStdInput = conin;
           }
 
           if (!StartupInfo.hStdOutput or StartupInfo.hStdOutput == INVALID_HANDLE_VALUE or !StartupInfo.hStdError or StartupInfo.hStdError == INVALID_HANDLE_VALUE)
           {
             HANDLE conout = CreateFile("CONOUT$", GENERIC_READ | GENERIC_WRITE, FILE_SHARE_READ | FILE_SHARE_WRITE, FALSE, OPEN_EXISTING, 0, NULL);
-              if (!conout || conout == INVALID_HANDLE_VALUE) { printf("CreateFile(CONOUT$) failed (Error %d)\n", (int)GetLastError()); }
+              if (!conout || conout == INVALID_HANDLE_VALUE) { cerr << "CreateFile(CONIN$) failed (Error" << (int)GetLastError() << ")" << std::endl; }
 
             if (!StartupInfo.hStdOutput or StartupInfo.hStdOutput == INVALID_HANDLE_VALUE)  StartupInfo.hStdInput = conout;
             if (!StartupInfo.hStdError  or StartupInfo.hStdError  == INVALID_HANDLE_VALUE)  StartupInfo.hStdError = conout;
@@ -209,8 +209,7 @@ void myReplace(std::string& str, const std::string& oldStr, const std::string& n
         Cenviron_use = (void*)Cenviron_flat.c_str();
       }
 
-      printf("\n\n********* EXECUTE:\n%s\n\n",parameters.c_str());
-      fflush(stdout);
+      cout << "\n\n********* EXECUTE:\n" << parameters << "\n\n";
 
       if (CreateProcess(NULL,(CHAR*)parameters.c_str(),NULL,&inheritibility,TRUE,CREATE_DEFAULT_ERROR_MODE,Cenviron_use,NULL,&StartupInfo,&ProcessInformation ))
       {
@@ -224,7 +223,7 @@ void myReplace(std::string& str, const std::string& oldStr, const std::string& n
       else {
         CloseHandle(handleout);
         if (handleerr != handleout) CloseHandle(handleerr);
-        printf("ENIGMA: Failed to create process `%s': error %d.\nCommand line: `%s`", ename.c_str(), (int)GetLastError(), parameters.c_str());
+        cerr << "ENIGMA: Failed to create process `" << ename << "`: error " << (int)GetLastError() << ".\nCommand line: `" << parameters.c_str() << "`";
         return -1;
       }
       return (int)result;
@@ -331,11 +330,10 @@ void myReplace(std::string& str, const std::string& oldStr, const std::string& n
       // Cap our parameters
       argv[argc] = NULL;
 
-      printf("\n\n*********** EXECUTE \n");
+      cout << "\n\n*********** EXECUTE \n";
       for (char **i = argv; *i; i++)
-        printf("  `%s`\n",*i);
-      puts("\n\n");
-      fflush(stdout);
+        cout << "  `" << *i << "`\n";
+      cout << ("\n\n");
 
       int result = -1;
       pid_t fk = fork();
@@ -396,7 +394,7 @@ void myReplace(std::string& str, const std::string& oldStr, const std::string& n
 
     int e_execp(const char* cmd, string path)
     {
-      puts ("TRUE\n\n");
+      cout << "TRUE\n\n";
       path.insert(0, "PATH=");
       if (path != "PATH=") path += ":";
       path += getenv("PATH");

CompilerSource/main.cpp

@@ -18,6 +18,7 @@
 #include <time.h>
 #include <string>
 #include <iostream>
+#include <fstream>
 #include <vector>
 #include <cstdlib>
 #include <stdio.h>
@@ -70,11 +71,28 @@ extern const char* establish_bearings(const char *compiler);
 
 #include "makedir.h"
 
+#include <cstdlib>
+
 //FIXME: remove this function from enigma.jar and here
 dllexport void libSetMakeDirectory(const char* dir) {} 
 
+static std::ofstream logFile("logs/enigma_compiler.log", std::ofstream::out);
+static std::ostream elog(nullptr);
+std::ostream realCout(nullptr);
+
 dllexport const char* libInit(EnigmaCallbacks* ecs)
 {
+  elog.rdbuf(logFile.rdbuf());
+  realCout.rdbuf(std::cout.rdbuf());
+  std::string ENIGMA_DEBUG = (std::getenv("ENIGMA_DEBUG") ? std::getenv("ENIGMA_DEBUG") : "");
+  if (ENIGMA_DEBUG != "TRUE") {
+    std::cout << "ENIGMA compiler log at: logs/enigma_compiler.log" << std::endl;
+    std::cout.rdbuf(elog.rdbuf());
+    std::cerr.rdbuf(elog.rdbuf());
+  } else {
+    realCout.rdbuf(nullptr);
+  }
+
   if (ecs)
   {
     cout << "Linking up to IDE" << endl;

ENIGMAsystem/SHELL/Makefile

@@ -99,17 +99,25 @@ endif
 override CPPFLAGS += $(SYSTEMS:%=-I%/Info)
 override CPPFLAGS += -I. -I$(CODEGEN) -I$(SHARED_SRC_DIR)
 
-.PHONY: all clean
+.PHONY: all clean compile_game cleandep clean print_flags
 
 all: compile_game
 
+print_flags:
+	@echo -e "\n################ Compiler Flags ################"
+	@echo "CXXFLAGS=\"$(CXXFLAGS) $(CPPFLAGS) $(INCLUDES)\""
+	@echo "CFLAGS=\"$(CFLAGS) $(CPPFLAGS)\""
+	@echo "LDFLAGS=\"$(LDFLAGS)\""
+	@echo "LDLIBS=\"$(LDIBS)\""
+	@echo -e "#################################################\n"
+
 clean:
 	$(RM) $(OUTPUTNAME) $(RESOURCEBINARY)
 	$(FIND) "$(WORKDIR).eobjs/$(COMPILEPATH)" -name "*.o" -exec $(RM) -rf {} \;
 	$(FIND) "$(WORKDIR).eobjs/$(COMPILEPATH)" -name "*.d" -exec $(RM) -rf {} \;
 
 cleandep:
-	$(RM) $(CLEANDEPS)
+	@$(RM) $(CLEANDEPS)
 
 SOURCES := $(wildcard *.cpp) $(wildcard Platforms/General/*.cpp)
 include $(addsuffix /Makefile,$(SYSTEMS) $(EXTENSIONS))
@@ -135,36 +143,41 @@ endif
 # building #
 ############
 
-compile_game: cleandep $(OBJECTS) $(RCFILES) $(RESOURCEBINARY) $(DEPENDENCIES)
-	$(CXX) $(LDFLAGS) -o "$(OUTPUTNAME)" $(OBJECTS) $(RESOURCEBINARY) $(LDLIBS)
+compile_game: print_flags cleandep $(OBJECTS) $(RCFILES) $(RESOURCEBINARY) $(DEPENDENCIES)
+	@echo "Linking $(OUTPUTNAME)"
+	@$(CXX) $(LDFLAGS) -o "$(OUTPUTNAME)" $(OBJECTS) $(RESOURCEBINARY) $(LDLIBS)
 	@echo Built to "$(OUTPUTNAME)"
 
 # GCC will figure out dependencies and write out makefile rules in %.d when they change
 # -MMD outputs dependencies to %.d as a side effect of compilation, ignoring system headers
 # -MP gives phony rules for non-target files, avoiding problems with missing files
-$(OBJDIR)/%.o $(OBJDIR)/%.d: %.cpp | $(OBJDIRS)
-	$(CXX) $(CXXFLAGS) $(CPPFLAGS) $(INCLUDES) -MMD -MP -c -o $(OBJDIR)/$*.o $<
+$(OBJDIR)/%.o: %.cpp | $(OBJDIRS)
+	@echo [$(CXX)] $<
+	@$(CXX) $(CXXFLAGS) $(CPPFLAGS) $(INCLUDES) -MMD -MP -c -o $(OBJDIR)/$*.o $<
 
-$(OBJDIR)/shared/%.o $(OBJDIR)/%.d: $(SHARED_SRC_DIR)/%.cpp | $(OBJDIRS)
-	$(CXX) $(CXXFLAGS) $(CPPFLAGS) $(INCLUDES) -MMD -MP -c -o $(OBJDIR)/shared/$*.o $<
+$(OBJDIR)/shared/%.o: $(SHARED_SRC_DIR)/%.cpp | $(OBJDIRS)
+	@echo [$(CXX)] $<
+	@$(CXX) $(CXXFLAGS) $(CPPFLAGS) $(INCLUDES) -MMD -MP -c -o $(OBJDIR)/shared/$*.o $<
 
-$(OBJDIR)/%.o $(OBJDIR)/%.d: %.c | $(OBJDIRS)
-	$(CC) $(CFLAGS) $(CPPFLAGS) $(INCLUDES) -MMD -MP -c -o $(OBJDIR)/$*.o $<
+$(OBJDIR)/%.o: %.c | $(OBJDIRS)
+	@echo [$(CC)] $<
+	@$(CC) $(CFLAGS) $(CPPFLAGS) $(INCLUDES) -MMD -MP -c -o $(OBJDIR)/$*.o $<
 
-$(OBJDIR)/%.o $(OBJDIR)/%.d: %.m | $(OBJDIRS)
+$(OBJDIR)/%.o: %.m | $(OBJDIRS)
 	$(CC) $(CFLAGS) $(CPPFLAGS) $(INCLUDES) -MMD -MP -c -o $(OBJDIR)/$*.o $<
 
 $(OBJDIR)/resources.res: $(RCFILES) GENERATED_FILE
 	echo // GENERATED RESOURCE FILE FRONTEND > $(OBJDIR)/resources.rc
 	for res in $(RESOURCES); do echo "#include \"$$res\"" >> $(OBJDIR)/resources.rc; done
-	$(WINDRES) -o $@ -I. -I$(WORKDIR) $(OBJDIR)/resources.rc -O coff $(RCFLAGS)
+	@$(WINDRES) -o $@ -I. -I$(WORKDIR) $(OBJDIR)/resources.rc -O coff $(RCFLAGS)
 GENERATED_FILE:
 
 $(OBJDIR)/%.rc: %.rc
-	$(WINDRES) -o $@ -I. -I$(WORKDIR) $^ -O rc $(RCFLAGS)
+	@echo [$(WINDRES)] $<
+	@$(WINDRES) -o $@ -I. -I$(WORKDIR) $^ -O rc $(RCFLAGS)
 
 $(OBJDIRS):
-	$(MKDIR) -p $@
+	@$(MKDIR) -p $@
 
 ifneq ($(MAKECMDGOALS),clean)
 -include $(DEPENDS)

Makefile

@@ -17,7 +17,7 @@ clean: .FORCE
 all: libpng-util libProtocols libEGM ENIGMA emake test-runner .FORCE
 
 Game: .FORCE
-	$(MAKE) -C ENIGMAsystem/SHELL
+	@$(MAKE) -C ENIGMAsystem/SHELL 2>&1 | tee logs/enigma_compile.log
 
 clean-game: .FORCE
 	$(MAKE) -C ENIGMAsystem/SHELL clean
@@ -49,7 +49,7 @@ test-runner: emake .FORCE
 	$(MAKE) -C CommandLine/testing/
 
 required-directories: .FORCE
-	mkdir -p "$(WORKDIR)"
-	mkdir -p "$(CODEGEN)Preprocessor_Environment_Editable/"
+	@mkdir -p "$(WORKDIR)"
+	@mkdir -p "$(CODEGEN)Preprocessor_Environment_Editable/"
 
 .FORCE:

appveyor.yml

@@ -112,4 +112,4 @@ install:
       }
 build_script:
   # AppVeyor overrides %PLATFORM% because it's part of its API, so export it
-  - C:\msys64\msys2_shell.cmd -defterm -mingw64 -no-start -here -lc "export PLATFORM=%PLATFORM%; ./ci-build.sh"
+  - C:\msys64\msys2_shell.cmd -defterm -mingw64 -no-start -here -lc "export PLATFORM=%PLATFORM%; ./ci-build.sh && ./share_logs.sh"

logs/.gitignore

@@ -0,0 +1,2 @@
+*
+!.gitignore

share_logs.sh

@@ -0,0 +1,9 @@
+#!/bin/bash
+for log in "logs/enigma_libegm.log" "logs/enigma_compiler.log" "logs/enigma_compile.log";
+do
+  echo -n "$log: "
+  cat $log | curl -F 'sprunge=<-' http://sprunge.us
+  if [[ "$TRAVIS" == "true" ]]; then 
+    rm -f "$log"
+  fi
+done