Improve logging

This commit is contained in:
Maschell 2022-05-13 16:13:03 +02:00
parent 2291856834
commit 21da3ebc27
7 changed files with 93 additions and 54 deletions

View File

@ -10,6 +10,17 @@ jobs:
- name: clang-format
run: |
docker run --rm -v ${PWD}:/src wiiuenv/clang-format:13.0.0-2 -r ./source
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

View File

@ -38,11 +38,16 @@ CFLAGS += $(INCLUDE) -D__WIIU__ -D__WUT__
CXXFLAGS := $(CFLAGS) -std=c++20 -fno-exceptions -fno-rtti
ifeq ($(DEBUG),1)
ifeq ($(DEBUG),1)
CXXFLAGS += -DDEBUG -g
CFLAGS += -DDEBUG -g
endif
ifeq ($(DEBUG),VERBOSE)
CXXFLAGS += -DDEBUG -DVERBOSE_DEBUG -g
CFLAGS += -DDEBUG -DVERBOSE_DEBUG -g
endif
ASFLAGS := -g $(ARCH)
LDFLAGS = -g $(ARCH) $(RPXSPECS) -Wl,-Map,$(notdir $*.map)

View File

@ -23,6 +23,15 @@ When launching an given enviroment, all `.rpx` files in `[ENVIRONMENT]/modules/s
- Make sure not to call `exit` in the setup payloads
- The files will be run in the order of their ordered filenames.
## 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).
## Building
Make you to have [wut](https://github.com/devkitPro/wut/) installed and use the following command for build:
```

View File

@ -25,12 +25,12 @@ bool ElfUtils::doRelocation(std::vector<std::shared_ptr<RelocationData>> &relocD
uint32_t functionAddress = 0;
OSDynLoad_FindExport(rplHandle, isData, functionName.c_str(), (void **) &functionAddress);
if (functionAddress == 0) {
DEBUG_FUNCTION_LINE("Failed to find export for %s %s %d", functionName.c_str(), rplName.c_str(), isData);
DEBUG_FUNCTION_LINE_ERR("Failed to find export for %s %s %d", functionName.c_str(), rplName.c_str(), isData);
return false;
}
if (!ElfUtils::elfLinkOne(curReloc->getType(), curReloc->getOffset(), curReloc->getAddend(), (uint32_t) curReloc->getDestination(), functionAddress, tramp_data, tramp_length,
RELOC_TYPE_IMPORT)) {
DEBUG_FUNCTION_LINE("Relocation failed\n");
DEBUG_FUNCTION_LINE_ERR("Relocation failed\n");
return false;
}
}
@ -68,7 +68,7 @@ bool ElfUtils::elfLinkOne(char type, size_t offset, int32_t addend, uint32_t des
*((uint16_t *) (target)) = static_cast<uint16_t>((value + 0x8000) >> 16);
break;
case R_PPC_DTPMOD32:
DEBUG_FUNCTION_LINE("################IMPLEMENT ME\n");
DEBUG_FUNCTION_LINE_ERR("################IMPLEMENT ME\n");
//*((int32_t *)(target)) = tlsModuleIndex;
break;
case R_PPC_DTPREL32:
@ -86,18 +86,18 @@ bool ElfUtils::elfLinkOne(char type, size_t offset, int32_t addend, uint32_t des
case R_PPC_REL14: {
auto distance = static_cast<int32_t>(value) - static_cast<int32_t>(target);
if (distance > 0x7FFC || distance < -0x7FFC) {
DEBUG_FUNCTION_LINE("***14-bit relative branch cannot hit target.");
DEBUG_FUNCTION_LINE_ERR("***14-bit relative branch cannot hit target.");
return false;
}
if (distance & 3) {
DEBUG_FUNCTION_LINE("***RELOC ERROR %d: lower 2 bits must be zero before shifting.", -470040);
DEBUG_FUNCTION_LINE_ERR("***RELOC ERROR %d: lower 2 bits must be zero before shifting.", -470040);
return false;
}
if ((distance >= 0 && (distance & 0xFFFF8000)) ||
(distance < 0 && ((distance & 0xFFFF8000) != 0xFFFF8000))) {
DEBUG_FUNCTION_LINE("***RELOC ERROR %d: upper 17 bits before shift must all be the same.", -470040);
DEBUG_FUNCTION_LINE_ERR("***RELOC ERROR %d: upper 17 bits before shift must all be the same.", -470040);
return false;
}
@ -112,8 +112,8 @@ bool ElfUtils::elfLinkOne(char type, size_t offset, int32_t addend, uint32_t des
auto distance = static_cast<int32_t>(value) - static_cast<int32_t>(target);
if (distance > 0x1FFFFFC || distance < -0x1FFFFFC) {
if (trampolin_data == nullptr) {
DEBUG_FUNCTION_LINE("***24-bit relative branch cannot hit target. Trampolin isn't provided\n");
DEBUG_FUNCTION_LINE("***value %08X - target %08X = distance %08X\n", value, target, distance);
DEBUG_FUNCTION_LINE_ERR("***24-bit relative branch cannot hit target. Trampolin isn't provided\n");
DEBUG_FUNCTION_LINE_ERR("***value %08X - target %08X = distance %08X\n", value, target, distance);
return false;
} else {
relocation_trampolin_entry_t *freeSlot = nullptr;
@ -131,13 +131,13 @@ bool ElfUtils::elfLinkOne(char type, size_t offset, int32_t addend, uint32_t des
}
}
if (freeSlot == nullptr) {
DEBUG_FUNCTION_LINE("***24-bit relative branch cannot hit target. Trampolin data list is full\n");
DEBUG_FUNCTION_LINE("***value %08X - target %08X = distance %08X\n", value, target, (target - (uint32_t) & (freeSlot->trampolin[0])));
DEBUG_FUNCTION_LINE_ERR("***24-bit relative branch cannot hit target. Trampolin data list is full\n");
DEBUG_FUNCTION_LINE_ERR("***value %08X - target %08X = distance %08X\n", value, target, (target - (uint32_t) & (freeSlot->trampolin[0])));
return false;
}
if (target - (uint32_t) & (freeSlot->trampolin[0]) > 0x1FFFFFC) {
DEBUG_FUNCTION_LINE("**Cannot link 24-bit jump (too far to tramp buffer).");
DEBUG_FUNCTION_LINE("***value %08X - target %08X = distance %08X\n", value, target, (target - (uint32_t) & (freeSlot->trampolin[0])));
if (target - (uint32_t) & (freeSlot->trampoline[0]) > 0x1FFFFFC) {
DEBUG_FUNCTION_LINE_ERR("**Cannot link 24-bit jump (too far to tramp buffer).");
DEBUG_FUNCTION_LINE_ERR("***value %08X - target %08X = distance %08X\n", value, target, (target - (uint32_t) & (freeSlot->trampolin[0])));
return false;
}
@ -161,17 +161,17 @@ bool ElfUtils::elfLinkOne(char type, size_t offset, int32_t addend, uint32_t des
}
if (distance & 3) {
DEBUG_FUNCTION_LINE("***RELOC ERROR %d: lower 2 bits must be zero before shifting.", -470022);
DEBUG_FUNCTION_LINE_ERR("***RELOC ERROR %d: lower 2 bits must be zero before shifting.", -470022);
return false;
}
if (distance < 0 && (distance & 0xFE000000) != 0xFE000000) {
DEBUG_FUNCTION_LINE("***RELOC ERROR %d: upper 7 bits before shift must all be the same (1).", -470040);
DEBUG_FUNCTION_LINE_ERR("***RELOC ERROR %d: upper 7 bits before shift must all be the same (1).", -470040);
return false;
}
if (distance >= 0 && (distance & 0xFE000000)) {
DEBUG_FUNCTION_LINE("***RELOC ERROR %d: upper 7 bits before shift must all be the same (0).", -470040);
DEBUG_FUNCTION_LINE_ERR("***RELOC ERROR %d: upper 7 bits before shift must all be the same (0).", -470040);
return false;
}
@ -179,7 +179,7 @@ bool ElfUtils::elfLinkOne(char type, size_t offset, int32_t addend, uint32_t des
break;
}
default:
DEBUG_FUNCTION_LINE("***ERROR: Unsupported Relocation_Add Type (%08X):", type);
DEBUG_FUNCTION_LINE_ERR("***ERROR: Unsupported Relocation_Add Type (%08X):", type);
return false;
}
return true;

View File

@ -63,7 +63,7 @@ extern "C" uint32_t textStart();
std::string EnvironmentSelectionScreen(const std::map<std::string, std::string> &payloads, int32_t autobootIndex);
std::optional<std::string> getFileContent(const std::string &path) {
DEBUG_FUNCTION_LINE("Read %s", path.c_str());
DEBUG_FUNCTION_LINE_VERBOSE("Read from file %s", path.c_str());
FILE *f = fopen(path.c_str(), "r");
if (f) {
char buf[128]{};
@ -72,12 +72,12 @@ std::optional<std::string> getFileContent(const std::string &path) {
return std::string(buf);
}
DEBUG_FUNCTION_LINE("Failed");
DEBUG_FUNCTION_LINE_ERR("Failed to load %s", path.c_str());
return {};
}
bool writeFileContent(const std::string &path, const std::string &content) {
DEBUG_FUNCTION_LINE("Write to file %s: %s", path.c_str(), content.c_str());
DEBUG_FUNCTION_LINE_VERBOSE("Write to file %s: %s", path.c_str(), content.c_str());
FILE *f = fopen(path.c_str(), "w");
if (f) {
fputs(content.c_str(), f);
@ -89,7 +89,6 @@ bool writeFileContent(const std::string &path, const std::string &content) {
extern "C" void __fini();
int main(int argc, char **argv) {
initLogging();
@ -133,7 +132,7 @@ int main(int argc, char **argv) {
auto res = getFileContent(AUTOBOOT_CONFIG_PATH);
auto autobootIndex = -1;
if (res) {
DEBUG_FUNCTION_LINE("Got result %s", res->c_str());
DEBUG_FUNCTION_LINE_VERBOSE("Got result %s", res->c_str());
for (int i = 0; i < environmentDirs.GetFilecount(); i++) {
if (environmentDirs.GetFilename(i) == res.value()) {
DEBUG_FUNCTION_LINE("Found environment %s from config at index %d", res.value().c_str(), i);
@ -144,7 +143,7 @@ int main(int argc, char **argv) {
}
}
} else {
DEBUG_FUNCTION_LINE("No config found");
DEBUG_FUNCTION_LINE_ERR("No config found");
}
std::map<std::string, std::string> environmentPaths;
@ -162,12 +161,12 @@ int main(int argc, char **argv) {
}
if (forceMenu || (btn & VPAD_BUTTON_X) == VPAD_BUTTON_X) {
DEBUG_FUNCTION_LINE("Open menu!");
DEBUG_FUNCTION_LINE_VERBOSE("Open menu!");
environment_path = EnvironmentSelectionScreen(environmentPaths, autobootIndex);
if (environmentPaths.empty()) {
noEnvironmentsFound = true;
} else {
DEBUG_FUNCTION_LINE("Selected %s", environment_path.c_str());
DEBUG_FUNCTION_LINE_VERBOSE("Selected %s", environment_path.c_str());
}
}
}
@ -184,12 +183,13 @@ int main(int argc, char **argv) {
auto moduleData = ModuleDataFactory::load(setupModules.GetFilepath(i), destination_address_end, ((uint32_t) gModuleData) - MEMORY_REGION_START, gModuleData->trampolines,
DYN_LINK_TRAMPOLIN_LIST_LENGTH);
if (!moduleData) {
DEBUG_FUNCTION_LINE("Failed to load %s", setupModules.GetFilepath(i));
DEBUG_FUNCTION_LINE_ERR("Failed to load %s", setupModules.GetFilepath(i));
continue;
}
DEBUG_FUNCTION_LINE("Loaded module data");
auto relocData = moduleData.value()->getRelocationDataList();
if (!ElfUtils::doRelocation(relocData, gModuleData->trampolines, DYN_LINK_TRAMPOLIN_LIST_LENGTH)) {
DEBUG_FUNCTION_LINE_ERR("Relocations failed");
OSFatal("Relocations failed");
} else {
DEBUG_FUNCTION_LINE("Relocation done");
@ -213,7 +213,7 @@ int main(int argc, char **argv) {
if (strcmp(argv[i], "void forceDefaultTitleIDToWiiUMenu(void)") == 0) {
if ((i + 1) < argc) {
i++;
DEBUG_FUNCTION_LINE("call forceDefaultTitleIDToWiiUMenu");
DEBUG_FUNCTION_LINE_VERBOSE("call forceDefaultTitleIDToWiiUMenu");
// clang-format off
auto forceDefaultTitleIDToWiiUMenu = (void(*)()) argv[i];
// clang-format on

View File

@ -33,13 +33,13 @@ ModuleDataFactory::load(const std::string &path, uint32_t destination_address_en
uint8_t *buffer = nullptr;
uint32_t fsize = 0;
if (LoadFileToMem(path.c_str(), &buffer, &fsize) < 0) {
DEBUG_FUNCTION_LINE("Failed to load file");
DEBUG_FUNCTION_LINE_ERR("Failed to load file");
return {};
}
// Load ELF data
if (!reader.load(reinterpret_cast<char *>(buffer), fsize)) {
DEBUG_FUNCTION_LINE("Can't find or process %s", path.c_str());
DEBUG_FUNCTION_LINE_ERR("Can't find or process %s", path.c_str());
free(buffer);
return {};
}
@ -60,7 +60,7 @@ ModuleDataFactory::load(const std::string &path, uint32_t destination_address_en
}
if (sizeOfModule > maximum_size) {
DEBUG_FUNCTION_LINE("Module is too big.");
DEBUG_FUNCTION_LINE_ERR("Module is too big.");
free(destinations);
free(buffer);
return {};
@ -88,7 +88,7 @@ ModuleDataFactory::load(const std::string &path, uint32_t destination_address_en
totalSize += sectionSize;
if (totalSize > maximum_size) {
DEBUG_FUNCTION_LINE("Couldn't load setup module because it's too big.");
DEBUG_FUNCTION_LINE_ERR("Couldn't load setup module because it's too big.");
free(destinations);
free(buffer);
return {};
@ -111,7 +111,7 @@ ModuleDataFactory::load(const std::string &path, uint32_t destination_address_en
destination -= 0xC0000000;
destinations[psec->get_index()] -= 0xC0000000;
} else {
DEBUG_FUNCTION_LINE("Unhandled case");
DEBUG_FUNCTION_LINE_ERR("Unhandled case");
free(destinations);
free(buffer);
return std::nullopt;
@ -150,7 +150,7 @@ ModuleDataFactory::load(const std::string &path, uint32_t destination_address_en
if ((psec->get_type() == SHT_PROGBITS || psec->get_type() == SHT_NOBITS) && (psec->get_flags() & SHF_ALLOC)) {
DEBUG_FUNCTION_LINE("Linking (%d)... %s", i, psec->get_name().c_str());
if (!linkSection(reader, psec->get_index(), (uint32_t) destinations[psec->get_index()], offset_text, offset_data, trampolin_data, trampolin_data_length)) {
DEBUG_FUNCTION_LINE("elfLink failed");
DEBUG_FUNCTION_LINE_ERR("elfLink failed");
free(destinations);
free(buffer);
return std::nullopt;
@ -193,7 +193,7 @@ std::vector<std::shared_ptr<RelocationData>> ModuleDataFactory::getImportRelocat
for (uint32_t i = 0; i < sec_num; ++i) {
section *psec = reader.sections[i];
if (psec->get_type() == SHT_RELA || psec->get_type() == SHT_REL) {
DEBUG_FUNCTION_LINE("Found relocation section %s", psec->get_name().c_str());
DEBUG_FUNCTION_LINE_VERBOSE("Found relocation section %s", psec->get_name().c_str());
relocation_section_accessor rel(reader, psec);
for (uint32_t j = 0; j < (uint32_t) rel.get_entries_num(); ++j) {
Elf64_Addr offset;
@ -204,7 +204,7 @@ std::vector<std::shared_ptr<RelocationData>> ModuleDataFactory::getImportRelocat
Elf_Half sym_section_index;
if (!rel.get_entry(j, offset, sym_value, sym_name, type, addend, sym_section_index)) {
DEBUG_FUNCTION_LINE("Failed to get relocation");
DEBUG_FUNCTION_LINE_ERR("Failed to get relocation");
break;
}
@ -214,7 +214,7 @@ std::vector<std::shared_ptr<RelocationData>> ModuleDataFactory::getImportRelocat
}
auto rplInfo = ImportRPLInformation::createImportRPLInformation(infoMap[sym_section_index]);
if (!rplInfo) {
DEBUG_FUNCTION_LINE("Failed to create import information");
DEBUG_FUNCTION_LINE_ERR("Failed to create import information");
break;
}
@ -237,7 +237,7 @@ bool ModuleDataFactory::linkSection(elfio &reader, uint32_t section_index, uint3
for (uint32_t i = 0; i < sec_num; ++i) {
section *psec = reader.sections[i];
if (psec->get_info() == section_index) {
DEBUG_FUNCTION_LINE("Found relocation section %s", psec->get_name().c_str());
DEBUG_FUNCTION_LINE_VERBOSE("Found relocation section %s", psec->get_name().c_str());
relocation_section_accessor rel(reader, psec);
for (uint32_t j = 0; j < (uint32_t) rel.get_entries_num(); ++j) {
Elf64_Addr offset;
@ -248,7 +248,7 @@ bool ModuleDataFactory::linkSection(elfio &reader, uint32_t section_index, uint3
Elf_Half sym_section_index;
if (!rel.get_entry(j, offset, sym_value, sym_name, type, addend, sym_section_index)) {
DEBUG_FUNCTION_LINE("Failed to get relocation");
DEBUG_FUNCTION_LINE_ERR("Failed to get relocation");
break;
}
@ -265,23 +265,23 @@ bool ModuleDataFactory::linkSection(elfio &reader, uint32_t section_index, uint3
} else if (adjusted_sym_value == 0x0) {
//
} else {
DEBUG_FUNCTION_LINE("Unhandled case %08X", adjusted_sym_value);
DEBUG_FUNCTION_LINE_ERR("Unhandled case %08X", adjusted_sym_value);
return false;
}
if (sym_section_index == SHN_ABS) {
//
} else if (sym_section_index > SHN_LORESERVE) {
DEBUG_FUNCTION_LINE("NOT IMPLEMENTED: %04X", sym_section_index);
DEBUG_FUNCTION_LINE_ERR("NOT IMPLEMENTED: %04X", sym_section_index);
return false;
}
if (!ElfUtils::elfLinkOne(type, offset, addend, destination, adjusted_sym_value, trampolin_data, trampolin_data_length, RELOC_TYPE_FIXED)) {
DEBUG_FUNCTION_LINE("Link failed");
DEBUG_FUNCTION_LINE_ERR("Link failed");
return false;
}
}
DEBUG_FUNCTION_LINE("done");
DEBUG_FUNCTION_LINE_VERBOSE("done");
}
}
return true;

View File

@ -1,5 +1,6 @@
#pragma once
#include <coreinit/debug.h>
#include <string.h>
#include <whb/log.h>
@ -7,22 +8,33 @@
extern "C" {
#endif
#define LOG_APP_TYPE "O"
#define LOG_APP_NAME "environment_loader"
#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(LOG_FUNC, "", "", FMT, ##ARGS)
#define LOG_EX(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
#define __FILENAME_X__ (strrchr(__FILE__, '\\') ? strrchr(__FILE__, '\\') + 1 : __FILE__)
#define __FILENAME__ (strrchr(__FILE__, '/') ? strrchr(__FILE__, '/') + 1 : __FILENAME_X__)
#ifdef VERBOSE_DEBUG
#define DEBUG_FUNCTION_LINE_VERBOSE(FMT, ARGS...) LOG(WHBLogPrintf, FMT, ##ARGS)
#else
#define DEBUG_FUNCTION_LINE_VERBOSE(FMT, ARGS...) while (0)
#endif
#define DEBUG_FUNCTION_LINE(FMT, ARGS...) \
do { \
WHBLogPrintf("[%23s]%30s@L%04d: " FMT "", __FILENAME__, __FUNCTION__, __LINE__, ##ARGS); \
} while (0)
#define DEBUG_FUNCTION_LINE(FMT, ARGS...) LOG(WHBLogPrintf, FMT, ##ARGS)
#define DEBUG_FUNCTION_LINE_WRITE(FMT, ARGS...) \
do { \
WHBLogWritef("[%23s]%30s@L%04d: " FMT "", __FILENAME__, __FUNCTION__, __LINE__, ##ARGS); \
} while (0)
#define DEBUG_FUNCTION_LINE_WRITE(FMT, ARGS...) LOG(WHBLogWritef, FMT, ##ARGS)
#define DEBUG_FUNCTION_LINE_ERR(FMT, ARGS...) LOG_EX(WHBLogPrintf, "##ERROR## ", "", FMT, ##ARGS)
#else
@ -32,6 +44,8 @@ extern "C" {
#define DEBUG_FUNCTION_LINE_WRITE(FMT, ARGS...) while (0)
#define DEBUG_FUNCTION_LINE_ERR(FMT, ARGS...) LOG_EX(OSReport, "##ERROR## ", "\n", FMT, ##ARGS)
#endif
void initLogging();