Improve logging

.github/workflows/pr.yml

@@ -10,6 +10,17 @@ jobs:
     - name: clang-format
       run: |
         docker run --rm -v ${PWD}:/src  wiiuenv/clang-format:13.0.0-2 -r ./src
+  check-build-with-logging:
+    runs-on: ubuntu-18.04
+    needs: clang-format
+    steps:
+    - uses: actions/checkout@v2
+    - name: build binary with logging
+      run: |
+        docker build . -t builder
+        docker run --rm -v ${PWD}:/project builder make DEBUG=VERBOSE
+        docker run --rm -v ${PWD}:/project builder make clean
+        docker run --rm -v ${PWD}:/project builder make DEBUG=1
   build-binary:
     runs-on: ubuntu-18.04
     needs: clang-format

Makefile

@@ -46,6 +46,11 @@ CXXFLAGS += -DDEBUG -g
 CFLAGS += -DDEBUG -g
 endif
 
+ifeq ($(DEBUG),VERBOSE)
+CXXFLAGS += -DDEBUG -DVERBOSE_DEBUG -g
+CFLAGS += -DDEBUG -DVERBOSE_DEBUG -g
+endif
+
 LIBS	:= -lwups -lwut -lwupsbackend -lz -lrpxloader
 
 #-------------------------------------------------------------------------------

README.md

@@ -7,6 +7,17 @@
 2. Requires the [WiiUPluginLoaderBackend](https://github.com/wiiu-env/WiiUPluginLoaderBackend) in `sd:/wiiu/environments/[ENVIRONMENT]/modules`.
 3. Requires the [RPXLoadingModule](https://github.com/wiiu-env/RPXLoadingModule) in `sd:/wiiu/environments/[ENVIRONMENT]/modules`.
 
+## Buildflags
+
+### Logging
+Building via `make` only logs errors (via OSReport). To enable logging via the [LoggingModule](https://github.com/wiiu-env/LoggingModule) set `DEBUG` to `1` or `VERBOSE`.
+
+`make` Logs errors only (via OSReport).  
+`make DEBUG=1` Enables information and error logging via [LoggingModule](https://github.com/wiiu-env/LoggingModule).  
+`make DEBUG=VERBOSE` Enables verbose information and error logging via [LoggingModule](https://github.com/wiiu-env/LoggingModule).  
+
+If the [LoggingModule](https://github.com/wiiu-env/LoggingModule) is not present, it'll fallback to UDP (Port 4405) and [CafeOS](https://github.com/wiiu-env/USBSerialLoggingModule) logging.
+
 ## Building using the Dockerfile
 
 It's possible to use a docker image for building. This way you don't need anything installed on your host system.

src/main.cpp

@@ -27,8 +27,7 @@ void stopThread() {
 }
 
 ON_APPLICATION_REQUESTS_EXIT() {
-    DEBUG_FUNCTION_LINE("Kill wiiload thread");
+    DEBUG_FUNCTION_LINE("Stop wiiload thread");
-
     stopThread();
 
     deinitLogging();

src/utils/TcpReceiver.cpp

@@ -1,24 +1,19 @@
-#include <algorithm>
-#include <cstring>
-#include <string>
-#include <sysapp/launch.h>
-#include <vector>
-#include <zlib.h>
-
-#include <coreinit/cache.h>
-#include <coreinit/debug.h>
-#include <coreinit/dynload.h>
-#include <coreinit/ios.h>
-#include <coreinit/messagequeue.h>
-#include <coreinit/title.h>
-#include <sysapp/title.h>
-
 #include "TcpReceiver.h"
 #include "fs/FSUtils.h"
 #include "utils/net.h"
 #include "utils/utils.h"
+#include <algorithm>
+#include <coreinit/debug.h>
+#include <coreinit/dynload.h>
+#include <coreinit/title.h>
+#include <cstring>
 #include <rpxloader.h>
+#include <string>
+#include <sysapp/launch.h>
+#include <sysapp/title.h>
+#include <vector>
 #include <wups_backend/PluginUtils.h>
+#include <zlib.h>
 
 #define RPX_TEMP_PATH       "fs:/vol/external01/wiiu/apps/"
 #define RPX_TEMP_FILE       "fs:/vol/external01/wiiu/apps/temp.rpx"
@@ -44,8 +39,6 @@ TcpReceiver::~TcpReceiver() {
     }
 }
 
-#define wiiu_geterrno() (socketlasterr())
-
 void TcpReceiver::executeThread() {
     serverSocket = socket(AF_INET, SOCK_STREAM, IPPROTO_IP);
     if (serverSocket < 0) {
@@ -95,7 +88,7 @@ void TcpReceiver::executeThread() {
                     break;
                 }
         } else {
-            DEBUG_FUNCTION_LINE("Server socket accept failed %i %d", clientSocket, errno);
+            DEBUG_FUNCTION_LINE_ERR("Server socket accept failed socket: %i errno: %d", clientSocket, errno);
             OSSleepTicks(OSMicrosecondsToTicks(100000));
         }
     }
@@ -121,7 +114,6 @@ int32_t TcpReceiver::loadToMemory(int32_t clientSocket, uint32_t ipAddress) {
     }
 
     uint32_t bytesRead = 0;
-    DEBUG_FUNCTION_LINE("transfer start");
 
     auto *loadAddress = (unsigned char *) memalign(0x40, fileSize);
     if (!loadAddress) {
@@ -137,7 +129,7 @@ int32_t TcpReceiver::loadToMemory(int32_t clientSocket, uint32_t ipAddress) {
 
         int32_t ret = recv(clientSocket, loadAddress + bytesRead, blockSize, 0);
         if (ret <= 0) {
-            DEBUG_FUNCTION_LINE("Failure on reading file");
+            DEBUG_FUNCTION_LINE_ERR("Failed to receive file");
             break;
         }
 
@@ -146,7 +138,7 @@ int32_t TcpReceiver::loadToMemory(int32_t clientSocket, uint32_t ipAddress) {
 
     if (bytesRead != fileSize) {
         free(loadAddress);
-        DEBUG_FUNCTION_LINE("File loading not finished, %i of %i bytes received", bytesRead, fileSize);
+        DEBUG_FUNCTION_LINE_ERR("File loading not finished, %i of %i bytes received", bytesRead, fileSize);
         return FILE_READ_ERROR;
     }
 
@@ -166,6 +158,7 @@ int32_t TcpReceiver::loadToMemory(int32_t clientSocket, uint32_t ipAddress) {
             // Section is compressed, inflate
             inflatedData = (unsigned char *) malloc(fileSizeUnc);
             if (!inflatedData) {
+                DEBUG_FUNCTION_LINE_ERR("Failed to malloc data");
                 free(loadAddress);
 
                 return NOT_ENOUGH_MEMORY;
@@ -181,6 +174,7 @@ int32_t TcpReceiver::loadToMemory(int32_t clientSocket, uint32_t ipAddress) {
 
             ret = inflateInit(&s);
             if (ret != Z_OK) {
+                DEBUG_FUNCTION_LINE_ERR("inflateInit failed %i", ret);
                 free(loadAddress);
                 free(inflatedData);
 
@@ -195,6 +189,7 @@ int32_t TcpReceiver::loadToMemory(int32_t clientSocket, uint32_t ipAddress) {
 
             ret = inflate(&s, Z_FINISH);
             if (ret != Z_OK && ret != Z_STREAM_END) {
+                DEBUG_FUNCTION_LINE_ERR("inflate failed %i", ret);
                 free(loadAddress);
                 free(inflatedData);
 
@@ -207,6 +202,7 @@ int32_t TcpReceiver::loadToMemory(int32_t clientSocket, uint32_t ipAddress) {
             // Section is compressed, inflate
             inflatedData = (unsigned char *) malloc(fileSizeUnc);
             if (!inflatedData) {
+                DEBUG_FUNCTION_LINE_ERR("malloc failed");
                 free(loadAddress);
 
                 return NOT_ENOUGH_MEMORY;
@@ -215,8 +211,7 @@ int32_t TcpReceiver::loadToMemory(int32_t clientSocket, uint32_t ipAddress) {
             uLongf f       = fileSizeUnc;
             int32_t result = uncompress((Bytef *) &inflatedData[0], &f, (Bytef *) loadAddress, fileSize);
             if (result != Z_OK) {
-                DEBUG_FUNCTION_LINE("uncompress failed %i", result);
+                DEBUG_FUNCTION_LINE_ERR("uncompress failed %i", result);
-
                 return FILE_READ_ERROR;
             }
 
@@ -260,12 +255,14 @@ int32_t TcpReceiver::loadToMemory(int32_t clientSocket, uint32_t ipAddress) {
                     }
                 }
 
+#ifdef VERBOSE_DEBUG
                 for (auto &plugin : finalList) {
-                    DEBUG_FUNCTION_LINE("name: %s", plugin.getMetaInformation().getName().c_str());
+                    DEBUG_FUNCTION_LINE_VERBOSE("name: %s", plugin.getMetaInformation().getName().c_str());
-                    DEBUG_FUNCTION_LINE("author: %s", plugin.getMetaInformation().getAuthor().c_str());
+                    DEBUG_FUNCTION_LINE_VERBOSE("author: %s", plugin.getMetaInformation().getAuthor().c_str());
-                    DEBUG_FUNCTION_LINE("handle: %08X", plugin.getPluginData().getHandle());
+                    DEBUG_FUNCTION_LINE_VERBOSE("handle: %08X", plugin.getPluginData().getHandle());
-                    DEBUG_FUNCTION_LINE("====");
+                    DEBUG_FUNCTION_LINE_VERBOSE("====");
                 }
+#endif
 
                 if (PluginUtils::LoadAndLinkOnRestart(finalList) != 0) {
                     DEBUG_FUNCTION_LINE("Failed to load & link");
@@ -278,7 +275,7 @@ int32_t TcpReceiver::loadToMemory(int32_t clientSocket, uint32_t ipAddress) {
                 _SYSLaunchTitleWithStdArgsInNoSplash(OSGetTitleID(), nullptr);
                 return fileSize;
             } else {
-                DEBUG_FUNCTION_LINE("Failed to parse plugin");
+                DEBUG_FUNCTION_LINE_ERR("Failed to parse plugin");
             }
         }
         free(inflatedData);

src/utils/logger.h

@@ -1,5 +1,6 @@
 #pragma once
 
+#include <coreinit/debug.h>
 #include <string.h>
 #include <whb/log.h>
 
@@ -7,31 +8,53 @@
 extern "C" {
 #endif
 
-#ifdef DEBUG
+#define LOG_APP_TYPE                                                "P"
+#define LOG_APP_NAME                                                "wiiload"
 
 #define __FILENAME_X__                                              (strrchr(__FILE__, '\\') ? strrchr(__FILE__, '\\') + 1 : __FILE__)
 #define __FILENAME__                                                (strrchr(__FILE__, '/') ? strrchr(__FILE__, '/') + 1 : __FILENAME_X__)
 
+#define LOG(LOG_FUNC, FMT, ARGS...)                                 LOG_EX_DEFAULT(LOG_FUNC, "", "", FMT, ##ARGS)
+
+#define LOG_EX_DEFAULT(LOG_FUNC, LOG_LEVEL, LINE_END, FMT, ARGS...) LOG_EX(__FILENAME__, __FUNCTION__, __LINE__, LOG_FUNC, LOG_LEVEL, LINE_END, FMT, ##ARGS)
+
+#define LOG_EX(FILENAME, FUNCTION, LINE, LOG_FUNC, LOG_LEVEL, LINE_END, FMT, ARGS...)                                                        \
+    do {                                                                                                                                     \
+        LOG_FUNC("[(%s)%18s][%23s]%30s@L%04d: " LOG_LEVEL "" FMT "" LINE_END, LOG_APP_TYPE, LOG_APP_NAME, FILENAME, FUNCTION, LINE, ##ARGS); \
+    } while (0)
+
+#ifdef DEBUG
+
+#ifdef VERBOSE_DEBUG
+#define DEBUG_FUNCTION_LINE_VERBOSE(FMT, ARGS...)                              LOG(WHBLogPrintf, FMT, ##ARGS)
+#define DEBUG_FUNCTION_LINE_VERBOSE_EX(FILENAME, FUNCTION, LINE, FMT, ARGS...) LOG_EX(FILENAME, FUNCTION, LINE, WHBLogPrintf, "", "", FMT, ##ARGS);
+#else
 #define DEBUG_FUNCTION_LINE_VERBOSE(FMT, ARGS...)    while (0)
+#define DEBUG_FUNCTION_LINE_VERBOSE_EX(FMT, ARGS...) while (0)
+#endif
 
-#define DEBUG_FUNCTION_LINE(FMT, ARGS...)                                                        \
+#define DEBUG_FUNCTION_LINE(FMT, ARGS...)                                      LOG(WHBLogPrintf, FMT, ##ARGS)
-    do {                                                                                         \
-        WHBLogPrintf("[%23s]%30s@L%04d: " FMT "", __FILENAME__, __FUNCTION__, __LINE__, ##ARGS); \
-    } while (0)
 
-#define DEBUG_FUNCTION_LINE_WRITE(FMT, ARGS...)                                                  \
+#define DEBUG_FUNCTION_LINE_WRITE(FMT, ARGS...)                                LOG(WHBLogWritef, FMT, ##ARGS)
-    do {                                                                                         \
+
-        WHBLogWritef("[%23s]%30s@L%04d: " FMT "", __FILENAME__, __FUNCTION__, __LINE__, ##ARGS); \
+#define DEBUG_FUNCTION_LINE_ERR(FMT, ARGS...)                                  LOG_EX_DEFAULT(WHBLogPrintf, "##ERROR## ", "", FMT, ##ARGS)
-    } while (0)
+
+#define DEBUG_FUNCTION_LINE_ERR_LAMBDA(FILENAME, FUNCTION, LINE, FMT, ARGS...) LOG_EX(FILENAME, FUNCTION, LINE, WHBLogPrintf, "##ERROR## ", "", FMT, ##ARGS);
 
 #else
 
+#define DEBUG_FUNCTION_LINE_VERBOSE_EX(FMT, ARGS...)                           while (0)
+
 #define DEBUG_FUNCTION_LINE_VERBOSE(FMT, ARGS...)                              while (0)
 
 #define DEBUG_FUNCTION_LINE(FMT, ARGS...)                                      while (0)
 
 #define DEBUG_FUNCTION_LINE_WRITE(FMT, ARGS...)                                while (0)
 
+#define DEBUG_FUNCTION_LINE_ERR(FMT, ARGS...)                                  LOG_EX_DEFAULT(OSReport, "##ERROR## ", "\n", FMT, ##ARGS)
+
+#define DEBUG_FUNCTION_LINE_ERR_LAMBDA(FILENAME, FUNCTION, LINE, FMT, ARGS...) LOG_EX(FILENAME, FUNCTION, LINE, OSReport, "##ERROR## ", "\n", FMT, ##ARGS);
+
 #endif
 
 void initLogging();