Merge branch 'doctashay-logging2'

CMakeLists.txt

@@ -104,4 +104,4 @@ add_subdirectory(third-party/spdlog)
 # windows memory management lib
 IF (WIN32)
     add_subdirectory(third-party/mman)
-ENDIF ()
+ENDIF ()

decompiler/IR/CfgBuilder.cpp

@@ -1109,4 +1109,4 @@ std::shared_ptr<IR> build_cfg_ir(Function& function,
   } catch (std::runtime_error& e) {
     return nullptr;
   }
-}
+}

decompiler/config/jak1_ntsc_black_label.jsonc

@@ -229,4 +229,4 @@
          "dma-sync-fast", "bsp-camera-asm",
          "generic-none-dma-wait", "unpack-comp-rle", "level-remap-texture", "(method 10 collide-edge-hold-list)"
     ]
-}
+}

game/CMakeLists.txt

@@ -90,4 +90,3 @@ ELSE()
 
 ENDIF()
 
-

game/kernel/asm_funcs.asm

@@ -184,4 +184,4 @@ _call_goal_asm_win32:
   pop rbx
   pop rdx
   
-  ret
+  ret

game/kernel/kmachine.cpp

@@ -148,11 +148,11 @@ void InitParms(int argc, const char* const* argv) {
  * DONE, EXACT
  */
 void InitCD() {
-  spdlog::info("Initializing CD drive\nThis may take a while...\n");
+  spdlog::info("Initializing CD drive. This may take a while...");
   sceCdInit(SCECdINIT);
   sceCdMmode(SCECdDVD);
   while (sceCdDiskReady(0) == SCECdNotReady) {
-    spdlog::debug("Drive not ready... insert a disk!\n");
+    spdlog::debug("Drive not ready... insert a disk!");
   }
   spdlog::debug("Disk type {}\n", sceCdGetDiskType());
 }

game/main.cpp

@@ -11,8 +11,13 @@
 int main(int argc, char** argv) {
   while (true) {
     spdlog::set_level(spdlog::level::debug);
+    auto game_logger = spdlog::basic_logger_mt("GOAL Runtime", "logs/runtime.log");
+    spdlog::set_default_logger(game_logger);
+    spdlog::flush_on(spdlog::level::info);
+
     // run the runtime in a loop so we can reset the game and have it restart cleanly
-    spdlog::info("gk {}.{} OK!\n", versions::GOAL_VERSION_MAJOR, versions::GOAL_VERSION_MINOR);
+    spdlog::info("OpenGOAL Runtime {}.{}", versions::GOAL_VERSION_MAJOR,
+                 versions::GOAL_VERSION_MINOR);
 
     if (exec_runtime(argc, argv) == 2) {
       return 0;

game/overlord/fake_iso.cpp

@@ -216,7 +216,6 @@ uint32_t FS_GetLength(FileRecord* fr) {
  * This is an ISO FS API Function
  */
 LoadStackEntry* FS_Open(FileRecord* fr, int32_t offset) {
-  // printf("[OVERLORD] FS Open %s\n", fr->name);  // Added
   spdlog::debug("[OVERLORD] FS Open {}", fr->name);
   LoadStackEntry* selected = nullptr;
   // find first unused spot on load stack.
@@ -231,7 +230,6 @@ LoadStackEntry* FS_Open(FileRecord* fr, int32_t offset) {
       return selected;
     }
   }
-  // printf("[OVERLORD ISO CD] Failed to FS_Open %s\n", fr->name);
   spdlog::warn("[OVERLORD] Failed to FS Open {}", fr->name);
   ExitIOP();
   return nullptr;
@@ -243,7 +241,6 @@ LoadStackEntry* FS_Open(FileRecord* fr, int32_t offset) {
  * This is an ISO FS API Function
  */
 LoadStackEntry* FS_OpenWad(FileRecord* fr, int32_t offset) {
-  // printf("[OVERLORD] FS Open %s\n", fr->name);  // Added
   spdlog::debug("[OVERLORD] FS_OpenWad {}", fr->name);
   LoadStackEntry* selected = nullptr;
   for (uint32_t i = 0; i < MAX_OPEN_FILES; i++) {
@@ -254,7 +251,6 @@ LoadStackEntry* FS_OpenWad(FileRecord* fr, int32_t offset) {
       return selected;
     }
   }
-  // printf("[OVERLORD ISO CD] Failed to FS_OpenWad %s\n", fr->name);
   spdlog::warn("[OVERLORD] Failed to FS_OpenWad {}", fr->name);
   ExitIOP();
   return nullptr;
@@ -265,7 +261,6 @@ LoadStackEntry* FS_OpenWad(FileRecord* fr, int32_t offset) {
  * This is an ISO FS API Function
  */
 void FS_Close(LoadStackEntry* fd) {
-  // printf("[OVERLORD] FS Close %s\n", fd->fr->name);
   spdlog::debug("[OVERLORD] FS_Close {}", fd->fr->name);
 
   // close the FD
@@ -285,7 +280,6 @@ uint32_t FS_BeginRead(LoadStackEntry* fd, void* buffer, int32_t len) {
   int32_t real_size = len;
   if (len < 0) {
     // not sure what this is about...
-    // printf("[OVERLORD ISO CD] negative length warning!\n");
     spdlog::warn("[OVERLORD ISO CD] Negative length warning!");
     real_size = len + 0x7ff;
   }

game/overlord/iso_cd.cpp

@@ -231,7 +231,7 @@ u32 ReadDirectory(uint32_t sector, uint32_t size, uint32_t secBufID) {
     while (lsize > 0) {
       // ISO low-level read
       if (!ReadSectorsNow(lsector, 1, buffer)) {
-        printf("[OVERLORD ISO CD] Failed to read sector in ReadDirectory\n");
+        spdlog::info("[OVERLORD ISO CD] Failed to read sector in ReadDirectory!");
         return 0;
       }
       u8* lbuffer = buffer;
@@ -264,7 +264,7 @@ u32 ReadDirectory(uint32_t sector, uint32_t size, uint32_t secBufID) {
             }
           } else {
             if (sNumFiles == MAX_ISO_FILES) {
-              printf("[OVERLORD ISO CD] There are too many files on the disc!\n");
+              spdlog::info("[OVERLORD ISO CD] There are too many files on the disc!");
               return 0;
             }
 
@@ -283,7 +283,7 @@ u32 ReadDirectory(uint32_t sector, uint32_t size, uint32_t secBufID) {
       lsize -= 0x800;
     }
   } else {
-    printf("[OVERLORD ISO CD] ReadDirectory ran out of sector buffers!\n");
+    spdlog::info("[OVERLORD ISO CD] ReadDirectory ran out of sector buffers!");
   }
   return 1;
 }
@@ -354,7 +354,7 @@ void LoadMusicTweaks(u8* buffer) {
   FileRecord* fr = FS_FindIN(iso_name);
   if (!fr || !ReadSectorsNow(fr->location, 1, buffer)) {
     *(s32*)gMusicTweakInfo = 0;
-    printf("[OVERLORD ISO CD] Failed to load music tweaks!\n");
+    spdlog::warn("[OVERLORD ISO CD] Failed to load music tweaks!");
   } else {
     memcpy(gMusicTweakInfo, buffer, MUSIC_TWEAK_SIZE);
   }
@@ -373,8 +373,8 @@ void LoadDiscID() {
   MakeISOName(iso_name, "DISK_ID.DIZ");
   FileRecord* fr = FS_FindIN(iso_name);
   if (!fr) {
-    printf(
-        "[OVERLORD ISO CD] LoadDiscID failed to find DISK_ID.DIZ, using sector 0x400 instead!\n");
+    spdlog::warn(
+        "[OVERLORD ISO CD] LoadDiscID failed to find DISK_ID.DIZ, using sector 0x400 instead!");
     CD_ID_SectorNum = 0x400;
   } else {
     CD_ID_SectorNum = fr->location;
@@ -385,7 +385,7 @@ void LoadDiscID() {
   for (uint32_t i = 0; i < SECTOR_SIZE / 4; i++) {
     CD_ID_SectorSum += CD_ID_Sector[i];
   }
-  printf("[OVERLORD] DISK_ID.DIZ OK 0x%x\n", CD_ID_SectorSum);
+  spdlog::info("[OVERLORD] DISK_ID.DIZ OK 0x{}\n", CD_ID_SectorSum);
 }
 
 /*!
@@ -416,13 +416,13 @@ void SetRealSector() {
   } else {
     // it's a duplicated file, and duplicate read is enabled, so get the area 2 sector.
     _real_sector = _sector + sAreaDiff;
-    printf("[OVERLORD] Warning, adjusting real sector in SetRealSector\n");
+    spdlog::warn("[OVERLORD] Warning, adjusting real sector in SetRealSector");
   }
 
   // we suspect the game is pirated, load the wrong sector.
   if (pirated) {
     _real_sector += 3;
-    printf("pirated!\n");  // added, so I don't trip this by accident!
+    spdlog::warn("Pirated!");
   }
 }
 
@@ -466,13 +466,13 @@ int FS_Init(u8* buffer) {
 
     // read primary volume descriptor into buffer
     if (!ReadSectorsNow(0x10, 1, sSecBuffer[0])) {
-      printf("[OVERLORD ISO CD] Failed to read primary volume descriptor\n");
+      spdlog::warn("[OVERLORD ISO CD] Failed to read primary volume descriptor");
       return 1;
     }
 
     // check volume descriptor identifier
     if (memcmp(sSecBuffer[0] + 1, "CD001", 5)) {
-      printf("[OVERLORD ISO CD] Got the wrong volume descriptor identifier\n");
+      spdlog::warn("[OVERLORD ISO CD] Got the wrong volume descriptor identifier");
       char* cptr = (char*)sSecBuffer[0] + 1;
       printf("%c%c%c%c%c\n", cptr[0], cptr[1], cptr[2], cptr[3], cptr[4]);
       return 1;
@@ -482,7 +482,7 @@ int FS_Init(u8* buffer) {
     uint32_t path_table_sector = ReadU32(sSecBuffer[0] + 0x8c);
 
     if (!ReadSectorsNow(path_table_sector, 1, sSecBuffer[0])) {
-      printf("[OVERLORD ISO CD] Failed to read path table\n");
+      spdlog::warn("[OVERLORD ISO CD] Failed to read path");
       return 1;
     }
 
@@ -490,14 +490,14 @@ int FS_Init(u8* buffer) {
     uint32_t path_table_extent = ReadU32(sSecBuffer[0] + 2);
 
     if (!ReadSectorsNow(path_table_extent, 1, sSecBuffer[0])) {
-      printf("[OVERLORD ISO CD] Failed to read path table extent\n");
+      spdlog::warn("[OVERLORD ISO CD] Failed to read path table extent");
     }
 
     // read root directory
     add_files = true;
     uint32_t dir_size = ReadU32(sSecBuffer[0] + 10);
     if (!ReadDirectory(path_table_extent, dir_size, 0)) {
-      printf("[OVERLORD ISO CD] Failed to ReadDirectory\n");
+      spdlog::warn("[OVERLORD ISO CD] Failed to ReadDirectory");
       return 1;
     }
 
@@ -520,7 +520,7 @@ int FS_Init(u8* buffer) {
     }
     return 0;
   } else {
-    printf("[OVERLORD ISO CD] Bad Media Type\n");
+    spdlog::warn("[OVERLORD ISO CD] Bad Media Type!");
     return 1;
   }
 }
@@ -567,7 +567,7 @@ FileRecord* FS_FindIN(const char* iso_name) {
     }
 
     // we didn't get 1 GB of files, you're a pirate.
-    printf("pirated!\n");  // i added this so i know if it hangs here
+    spdlog::warn("Pirated!");
   }
 }
 
@@ -585,7 +585,7 @@ uint32_t FS_GetLength(FileRecord* fr) {
  * This is an ISO FS API Function
  */
 LoadStackEntry* FS_Open(FileRecord* fr, int32_t offset) {
-  printf("[OVERLORD] FS Open %s\n", fr->name);  // Added
+  spdlog::info("[OVERLORD] FS Open {}", fr->name);
   LoadStackEntry* selected = nullptr;
   // find first unused spot on load stack.
   for (uint32_t i = 0; i < MAX_OPEN_FILES; i++) {
@@ -599,7 +599,7 @@ LoadStackEntry* FS_Open(FileRecord* fr, int32_t offset) {
       return selected;
     }
   }
-  printf("[OVERLORD ISO CD] Failed to FS_Open %s\n", fr->name);
+  spdlog::warn("[OVERLORD ISO CD] Failed to FS_Open {}", fr->name);
   ExitIOP();
   return nullptr;
 }
@@ -620,7 +620,7 @@ LoadStackEntry* FS_OpenWad(FileRecord* fr, int32_t offset) {
       return selected;
     }
   }
-  printf("[OVERLORD ISO CD] Failed to FS_OpenWad %s\n", fr->name);
+  spdlog::warn("[OVERLORD ISO CD] Failed to use FS_OpenWad {}", fr->name);
   ExitIOP();
   return nullptr;
 }
@@ -630,7 +630,7 @@ LoadStackEntry* FS_OpenWad(FileRecord* fr, int32_t offset) {
  * This is an ISO FS API Function
  */
 void FS_Close(LoadStackEntry* fd) {
-  printf("[OVERLORD] FS Close %s\n", fd->fr->name);
+  spdlog::info("[OVERLORD] FS Close {}", fd->fr->name);
   if (fd == sReadInfo) {
     // the file is currently being read, so lets try to finish out the read, if possible.
     int count = 0;
@@ -663,7 +663,7 @@ uint32_t FS_BeginRead(LoadStackEntry* fd, void* buffer, int32_t len) {
   int32_t real_size = len;
   if (len < 0) {
     // not sure what this is about...
-    printf("[OVERLORD ISO CD] negative length warning!\n");
+    spdlog::warn("[OVERLORD ISO CD] Negative length warning!");
     real_size = len + 0x7ff;
   }
   _sectors = real_size >> 11;
@@ -982,4 +982,4 @@ void CD_WaitReturn() {
     }
   } while (!CheckDiskID());
   gNoCD = 0;
-}
+}

game/overlord/iso_queue.cpp

@@ -179,11 +179,11 @@ u32 QueueMessage(IsoMessage* cmd, int32_t priority, const char* name) {
     gPriStack[priority].cmds[gPriStack[priority].n] = cmd;
     gPriStack[priority].names[gPriStack[priority].n] = name;
     gPriStack[priority].n++;
-    printf("[OVERLORD] Queue %d (%d/%d), %s\n", priority, gPriStack[priority].n, PRI_STACK_LENGTH,
-           gPriStack[priority].names[gPriStack[priority].n - 1].c_str());
+    spdlog::debug("[OVERLORD] Queue {} ({}/{}), {}", priority, gPriStack[priority].n,
+                  PRI_STACK_LENGTH, gPriStack[priority].names[gPriStack[priority].n - 1].c_str());
     DisplayQueue();
   } else {
-    printf("[OVERLORD ISO QUEUE] Failed to queue!\n");
+    spdlog::warn("[OVERLORD ISO QUEUE] Failed to queue!");
     cmd->status = CMD_STATUS_FAILED_TO_QUEUE;
     ReturnMessage(cmd);
   }
@@ -209,7 +209,7 @@ void UnqueueMessage(IsoMessage* cmd) {
       }
     }
   }
-  printf("[OVERLORD ISO QUEUE] Failed to unqueue!\n");
+  spdlog::warn("[OVERLORD ISO QUEUE] Failed to unqueue!");
 
 found:
   assert(gPriStack[pri].cmds[idx] == cmd);

game/runtime.cpp

@@ -75,7 +75,7 @@ void deci2_runner(SystemThreadInterface& iface) {
     throw std::runtime_error("DECI2 server init failed");
   }
 
-  printf("[DECI2] waiting for listener...\n");
+  spdlog::debug("[DECI2] Waiting for listener...");
   // spdlog::debug("[DECI2] Waiting for listener..."); --> disabled temporarily, some weird race
   // condition?
   bool saw_listener = false;
@@ -259,7 +259,6 @@ u32 exec_runtime(int argc, char** argv) {
 
   // join and exit
   tm.join();
-  // printf("GOAL Runtime Shutdown (code %d)\n", MasterExit);
   spdlog::info("GOAL Runtime Shutdown (code {})", MasterExit);
   return MasterExit;
 }