improved logging in elf loader

This commit is contained in:
georgemoralis 2023-10-27 18:28:05 +03:00
parent eb67c847a7
commit af3710887c
1 changed files with 110 additions and 163 deletions

View File

@ -1,142 +1,90 @@
#include <bit>
#include <fmt/core.h>
#include <spdlog/pattern_formatter.h>
#include <spdlog/sinks/stdout_color_sinks.h>
#include <spdlog/sinks/basic_file_sink.h>
#include <spdlog/spdlog.h>
#include <debug.h>
#include "Elf.h"
#include <Util/log.h>
#include <debug.h>
#include <fmt/core.h>
constexpr bool log_file_loader = true; // disable it to disable logging
static std::string_view getProgramTypeName(program_type_es type) {
switch (type) {
case PT_FAKE:
return "PT_FAKE";
case PT_NPDRM_EXEC:
return "PT_NPDRM_EXEC";
case PT_NPDRM_DYNLIB:
return "PT_NPDRM_DYNLIB";
case PT_SYSTEM_EXEC:
return "PT_SYSTEM_EXEC";
case PT_SYSTEM_DYNLIB:
return "PT_SYSTEM_DYNLIB";
case PT_HOST_KERNEL:
return "PT_HOST_KERNEL";
case PT_SECURE_MODULE:
return "PT_SECURE_MODULE";
case PT_SECURE_KERNEL:
return "PT_SECURE_KERNEL";
default:
return "INVALID";
case PT_FAKE: return "PT_FAKE";
case PT_NPDRM_EXEC: return "PT_NPDRM_EXEC";
case PT_NPDRM_DYNLIB: return "PT_NPDRM_DYNLIB";
case PT_SYSTEM_EXEC: return "PT_SYSTEM_EXEC";
case PT_SYSTEM_DYNLIB: return "PT_SYSTEM_DYNLIB";
case PT_HOST_KERNEL: return "PT_HOST_KERNEL";
case PT_SECURE_MODULE: return "PT_SECURE_MODULE";
case PT_SECURE_KERNEL: return "PT_SECURE_KERNEL";
default: return "INVALID";
}
}
static std::string_view getIdentClassName(ident_class_es elf_class) {
switch (elf_class) {
case ELF_CLASS_NONE:
return "ELF_CLASS_NONE";
case ELF_CLASS_32:
return "ELF_CLASS_32";
case ELF_CLASS_64:
return "ELF_CLASS_64";
case ELF_CLASS_NUM:
return "ELF_CLASS_NUM";
default:
return "INVALID";
case ELF_CLASS_NONE: return "ELF_CLASS_NONE";
case ELF_CLASS_32: return "ELF_CLASS_32";
case ELF_CLASS_64: return "ELF_CLASS_64";
case ELF_CLASS_NUM: return "ELF_CLASS_NUM";
default: return "INVALID";
}
}
static std::string_view getIdentEndianName(ident_endian_es endian) {
switch (endian) {
case ELF_DATA_NONE:
return "ELF_DATA_NONE";
case ELF_DATA_2LSB:
return "ELF_DATA_2LSB";
case ELF_DATA_2MSB:
return "ELF_DATA_2MSB";
case ELF_DATA_NUM:
return "ELF_DATA_NUM";
default:
return "INVALID";
case ELF_DATA_NONE: return "ELF_DATA_NONE";
case ELF_DATA_2LSB: return "ELF_DATA_2LSB";
case ELF_DATA_2MSB: return "ELF_DATA_2MSB";
case ELF_DATA_NUM: return "ELF_DATA_NUM";
default: return "INVALID";
}
}
static std::string_view getIdentVersionName(ident_version_es version) {
switch (version) {
case ELF_VERSION_NONE:
return "ELF_VERSION_NONE";
case ELF_VERSION_CURRENT:
return "ELF_VERSION_CURRENT";
case ELF_VERSION_NUM:
return "ELF_VERSION_NUM";
default:
return "INVALID";
case ELF_VERSION_NONE: return "ELF_VERSION_NONE";
case ELF_VERSION_CURRENT: return "ELF_VERSION_CURRENT";
case ELF_VERSION_NUM: return "ELF_VERSION_NUM";
default: return "INVALID";
}
}
static std::string_view getIdentOsabiName(ident_osabi_es osabi) {
switch (osabi) {
case ELF_OSABI_NONE:
return "ELF_OSABI_NONE";
case ELF_OSABI_HPUX:
return "ELF_OSABI_HPUX";
case ELF_OSABI_NETBSD:
return "ELF_OSABI_NETBSD";
case ELF_OSABI_LINUX:
return "ELF_OSABI_LINUX";
case ELF_OSABI_SOLARIS:
return "ELF_OSABI_SOLARIS";
case ELF_OSABI_AIX:
return "ELF_OSABI_AIX";
case ELF_OSABI_IRIX:
return "ELF_OSABI_IRIX";
case ELF_OSABI_FREEBSD:
return "ELF_OSABI_FREEBSD";
case ELF_OSABI_TRU64:
return "ELF_OSABI_TRU64";
case ELF_OSABI_MODESTO:
return "ELF_OSABI_MODESTO";
case ELF_OSABI_OPENBSD:
return "ELF_OSABI_OPENBSD";
case ELF_OSABI_OPENVMS:
return "ELF_OSABI_OPENVMS";
case ELF_OSABI_NSK:
return "ELF_OSABI_NSK";
case ELF_OSABI_AROS:
return "ELF_OSABI_AROS";
case ELF_OSABI_ARM_AEABI:
return "ELF_OSABI_ARM_AEABI";
case ELF_OSABI_ARM:
return "ELF_OSABI_ARM";
case ELF_OSABI_STANDALONE:
return "ELF_OSABI_STANDALONE";
default:
return "INVALID";
case ELF_OSABI_NONE: return "ELF_OSABI_NONE";
case ELF_OSABI_HPUX: return "ELF_OSABI_HPUX";
case ELF_OSABI_NETBSD: return "ELF_OSABI_NETBSD";
case ELF_OSABI_LINUX: return "ELF_OSABI_LINUX";
case ELF_OSABI_SOLARIS: return "ELF_OSABI_SOLARIS";
case ELF_OSABI_AIX: return "ELF_OSABI_AIX";
case ELF_OSABI_IRIX: return "ELF_OSABI_IRIX";
case ELF_OSABI_FREEBSD: return "ELF_OSABI_FREEBSD";
case ELF_OSABI_TRU64: return "ELF_OSABI_TRU64";
case ELF_OSABI_MODESTO: return "ELF_OSABI_MODESTO";
case ELF_OSABI_OPENBSD: return "ELF_OSABI_OPENBSD";
case ELF_OSABI_OPENVMS: return "ELF_OSABI_OPENVMS";
case ELF_OSABI_NSK: return "ELF_OSABI_NSK";
case ELF_OSABI_AROS: return "ELF_OSABI_AROS";
case ELF_OSABI_ARM_AEABI: return "ELF_OSABI_ARM_AEABI";
case ELF_OSABI_ARM: return "ELF_OSABI_ARM";
case ELF_OSABI_STANDALONE: return "ELF_OSABI_STANDALONE";
default: return "INVALID";
}
}
static std::string_view getIdentAbiversionName(ident_abiversion_es version) {
switch (version) {
case ELF_ABI_VERSION_AMDGPU_HSA_V2:
return "ELF_ABI_VERSION_AMDGPU_HSA_V2";
case ELF_ABI_VERSION_AMDGPU_HSA_V3:
return "ELF_ABI_VERSION_AMDGPU_HSA_V3";
case ELF_ABI_VERSION_AMDGPU_HSA_V4:
return "ELF_ABI_VERSION_AMDGPU_HSA_V4";
case ELF_ABI_VERSION_AMDGPU_HSA_V5:
return "ELF_ABI_VERSION_AMDGPU_HSA_V5";
default:
return "INVALID";
case ELF_ABI_VERSION_AMDGPU_HSA_V2: return "ELF_ABI_VERSION_AMDGPU_HSA_V2";
case ELF_ABI_VERSION_AMDGPU_HSA_V3: return "ELF_ABI_VERSION_AMDGPU_HSA_V3";
case ELF_ABI_VERSION_AMDGPU_HSA_V4: return "ELF_ABI_VERSION_AMDGPU_HSA_V4";
case ELF_ABI_VERSION_AMDGPU_HSA_V5: return "ELF_ABI_VERSION_AMDGPU_HSA_V5";
default: return "INVALID";
}
}
Elf::~Elf() {
Reset();
}
Elf::~Elf() { Reset(); }
void Elf::Reset() {
m_f.close();
}
void Elf::Reset() { m_f.close(); }
void Elf::Open(const std::string& file_name) {
Reset();
@ -191,18 +139,18 @@ void Elf::Open(const std::string& file_name) {
bool Elf::isSelfFile() const {
if (m_self.magic != self_header::signature) [[unlikely]] {
fmt::print("Not a SELF file. Magic file mismatched! current = {:#x} required = {:#x}\n",
m_self.magic, self_header::signature);
LOG_ERROR_IF(log_file_loader, "Not a SELF file.Magic file mismatched !current = {} required = {}\n ", log_hex_full(m_self.magic),
log_hex_full(self_header::signature));
return false;
}
if (m_self.version != 0x00 || m_self.mode != 0x01 || m_self.endian != 0x01 || m_self.attributes != 0x12) [[unlikely]] {
fmt::print("Unknown SELF file\n");
LOG_ERROR_IF(log_file_loader, "Unknown SELF file\n");
return false;
}
if (m_self.category != 0x01 || m_self.program_type != 0x01) [[unlikely]] {
fmt::print("Unknown SELF file\n");
LOG_ERROR_IF(log_file_loader, "Unknown SELF file\n");
return false;
}
@ -212,58 +160,59 @@ bool Elf::isSelfFile() const {
bool Elf::isElfFile() const {
if (m_elf_header.e_ident.magic[EI_MAG0] != ELFMAG0 || m_elf_header.e_ident.magic[EI_MAG1] != ELFMAG1 ||
m_elf_header.e_ident.magic[EI_MAG2] != ELFMAG2 || m_elf_header.e_ident.magic[EI_MAG3] != ELFMAG3) {
fmt::print("ERROR:Not an ELF file magic is wrong!\n");
LOG_ERROR_IF(log_file_loader, "Not an ELF file magic is wrong!\n");
return false;
}
if (m_elf_header.e_ident.ei_class != ELF_CLASS_64) {
fmt::print("ERROR:e_ident[EI_CLASS] expected 0x02 is ({:#x})\n", static_cast<u32>(m_elf_header.e_ident.ei_class));
LOG_ERROR_IF(log_file_loader, "e_ident[EI_CLASS] expected 0x02 is ({})\n", log_hex_full(static_cast<u32>(m_elf_header.e_ident.ei_class)));
return false;
}
if (m_elf_header.e_ident.ei_data != ELF_DATA_2LSB) {
fmt::print("ERROR:e_ident[EI_DATA] expected 0x01 is ({:#x})\n", static_cast<u32>(m_elf_header.e_ident.ei_data));
LOG_ERROR_IF(log_file_loader, "e_ident[EI_DATA] expected 0x01 is ({})\n", log_hex_full(static_cast<u32>(m_elf_header.e_ident.ei_data)));
return false;
}
if (m_elf_header.e_ident.ei_version != ELF_VERSION_CURRENT) {
fmt::print("ERROR:e_ident[EI_VERSION] expected 0x01 is ({:#x})\n", static_cast<u32>(m_elf_header.e_ident.ei_version));
LOG_ERROR_IF(log_file_loader, "e_ident[EI_VERSION] expected 0x01 is ({})\n", log_hex_full(static_cast<u32>(m_elf_header.e_ident.ei_version)));
return false;
}
if (m_elf_header.e_ident.ei_osabi != ELF_OSABI_FREEBSD) {
fmt::print("ERROR:e_ident[EI_OSABI] expected 0x09 is ({:#x})\n", static_cast<u32>(m_elf_header.e_ident.ei_osabi));
LOG_ERROR_IF(log_file_loader, "e_ident[EI_OSABI] expected 0x09 is ({})\n", log_hex_full(static_cast<u32>(m_elf_header.e_ident.ei_osabi)));
return false;
}
if (m_elf_header.e_ident.ei_abiversion != ELF_ABI_VERSION_AMDGPU_HSA_V2) {
fmt::print("ERROR:e_ident[EI_ABIVERSION] expected 0x00 is ({:#x})\n", static_cast<u32>(m_elf_header.e_ident.ei_abiversion));
LOG_ERROR_IF(log_file_loader, "e_ident[EI_ABIVERSION] expected 0x00 is ({})\n",
log_hex_full(static_cast<u32>(m_elf_header.e_ident.ei_abiversion)));
return false;
}
if (m_elf_header.e_type != ET_SCE_DYNEXEC && m_elf_header.e_type != ET_SCE_DYNAMIC && m_elf_header.e_type != ET_SCE_EXEC) {
fmt::print("ERROR:e_type expected 0xFE10 OR 0xFE18 OR 0xfe00 is ({:#x})\n", static_cast<u32>(m_elf_header.e_type));
LOG_ERROR_IF(log_file_loader, "e_type expected 0xFE10 OR 0xFE18 OR 0xfe00 is ({})\n", log_hex_full(static_cast<u32>(m_elf_header.e_type)));
return false;
}
if (m_elf_header.e_machine != EM_X86_64) {
fmt::print("ERROR:e_machine expected 0x3E is ({:#x})\n", static_cast<u32>(m_elf_header.e_machine));
LOG_ERROR_IF(log_file_loader, "e_machine expected 0x3E is ({})\n", log_hex_full(static_cast<u32>(m_elf_header.e_machine)));
return false;
}
if (m_elf_header.e_version != EV_CURRENT) {
fmt::print("ERROR:m_elf_header.e_version expected 0x01 is ({:#x})\n", static_cast<u32>(m_elf_header.e_version));
LOG_ERROR_IF(log_file_loader, "m_elf_header.e_version expected 0x01 is ({})\n", log_hex_full(static_cast<u32>(m_elf_header.e_version)));
return false;
}
if (m_elf_header.e_phentsize != sizeof(elf_program_header)) {
fmt::print("ERROR:e_phentsize ({}) != sizeof(elf_program_header)\n", static_cast<u32>(m_elf_header.e_phentsize));
LOG_ERROR_IF(log_file_loader, "e_phentsize ({}) != sizeof(elf_program_header)\n", static_cast<u32>(m_elf_header.e_phentsize));
return false;
}
if (m_elf_header.e_shentsize > 0 &&
m_elf_header.e_shentsize != sizeof(elf_section_header)) // Commercial games doesn't appear to have section headers
{
fmt::print("ERROR:e_shentsize ({}) != sizeof(elf_section_header)\n", m_elf_header.e_shentsize);
LOG_ERROR_IF(log_file_loader, "e_shentsize ({}) != sizeof(elf_section_header)\n", m_elf_header.e_shentsize);
return false;
}
@ -272,70 +221,68 @@ bool Elf::isElfFile() const {
void Elf::DebugDump() {
if (is_self) { // If we load elf instead
spdlog::info(SElfHeaderStr());
spdlog::info("\n");
LOG_INFO_IF(log_file_loader,(SElfHeaderStr()));
for (u16 i = 0; i < m_self.segment_count; i++) {
spdlog::info(SELFSegHeader(i));
LOG_INFO_IF(log_file_loader, SELFSegHeader(i));
}
spdlog::info("\n");
}
spdlog::info(ElfHeaderStr());
LOG_INFO_IF(log_file_loader, ElfHeaderStr());
if (m_elf_header.e_phentsize > 0) {
spdlog::info("Program headers:\n");
LOG_INFO_IF(log_file_loader, "Program headers:\n");
for (u16 i = 0; i < m_elf_header.e_phnum; i++) {
spdlog::info(ElfPHeaderStr(i));
LOG_INFO_IF(log_file_loader, ElfPHeaderStr(i));
}
}
if (m_elf_header.e_shentsize > 0) {
spdlog::info("Section headers:\n");
LOG_INFO_IF(log_file_loader,"Section headers:\n");
for (u16 i = 0; i < m_elf_header.e_shnum; i++) {
spdlog::info("--- shdr {} --\n", i);
spdlog::info("sh_name ........: {}\n", m_elf_shdr[i].sh_name);
spdlog::info("sh_type ........: {:#010x}\n", m_elf_shdr[i].sh_type);
spdlog::info("sh_flags .......: {:#018x}\n", m_elf_shdr[i].sh_flags);
spdlog::info("sh_addr ........: {:#018x}\n", m_elf_shdr[i].sh_addr);
spdlog::info("sh_offset ......: {:#018x}\n", m_elf_shdr[i].sh_offset);
spdlog::info("sh_size ........: {:#018x}\n", m_elf_shdr[i].sh_size);
spdlog::info("sh_link ........: {:#010x}\n", m_elf_shdr[i].sh_link);
spdlog::info("sh_info ........: {:#010x}\n", m_elf_shdr[i].sh_info);
spdlog::info("sh_addralign ...: {:#018x}\n", m_elf_shdr[i].sh_addralign);
spdlog::info("sh_entsize .....: {:#018x}\n", m_elf_shdr[i].sh_entsize);
LOG_INFO_IF(log_file_loader, "--- shdr {} --\n", i);
LOG_INFO_IF(log_file_loader, "sh_name ........: {}\n", log_hex_full(m_elf_shdr[i].sh_name));
LOG_INFO_IF(log_file_loader, "sh_type ........: {}\n", log_hex_full(m_elf_shdr[i].sh_type));
LOG_INFO_IF(log_file_loader, "sh_flags .......: {}\n", log_hex_full(m_elf_shdr[i].sh_flags));
LOG_INFO_IF(log_file_loader, "sh_addr ........: {}\n", log_hex_full(m_elf_shdr[i].sh_addr));
LOG_INFO_IF(log_file_loader, "sh_offset ......: {}\n", log_hex_full(m_elf_shdr[i].sh_offset));
LOG_INFO_IF(log_file_loader, "sh_size ........: {}\n", log_hex_full(m_elf_shdr[i].sh_size));
LOG_INFO_IF(log_file_loader, "sh_link ........: {}\n", log_hex_full(m_elf_shdr[i].sh_link));
LOG_INFO_IF(log_file_loader, "sh_info ........: {}\n", log_hex_full(m_elf_shdr[i].sh_info));
LOG_INFO_IF(log_file_loader, "sh_addralign ...: {}\n", log_hex_full(m_elf_shdr[i].sh_addralign));
LOG_INFO_IF(log_file_loader, "sh_entsize .....: {}\n", log_hex_full(m_elf_shdr[i].sh_entsize));
}
}
if (is_self) {
spdlog::info("SELF info:\n");
spdlog::info("auth id ............: {:#018x}\n", m_self_id_header.authid);
spdlog::info("program type .......: {}\n", getProgramTypeName(m_self_id_header.program_type));
spdlog::info("app version ........: {:#018x}\n", m_self_id_header.appver);
spdlog::info("fw version .........: {:#018x}\n", m_self_id_header.firmver);
LOG_INFO_IF(log_file_loader, "SELF info:\n");
LOG_INFO_IF(log_file_loader, "auth id ............: {}\n", log_hex_full(m_self_id_header.authid));
LOG_INFO_IF(log_file_loader, "program type .......: {}\n", getProgramTypeName(m_self_id_header.program_type));
LOG_INFO_IF(log_file_loader, "app version ........: {}\n", log_hex_full(m_self_id_header.appver));
LOG_INFO_IF(log_file_loader, "fw version .........: {}\n", log_hex_full(m_self_id_header.firmver));
std::string digest;
for (int i = 0; i < 32; i++) {
digest += fmt::format("{:02X}", m_self_id_header.digest[i]);
}
spdlog::info("digest..............: 0x{}\n",digest);
LOG_INFO_IF(log_file_loader, "digest..............: 0x{}\n", digest);
}
}
std::string Elf::SElfHeaderStr() {
std::string header = fmt::format("======= SELF HEADER =========\n", m_self.magic);
header += fmt::format("magic ..............: 0x{:X}\n", m_self.magic);
header += fmt::format("magic ..............: {}\n", log_hex_full(m_self.magic));
header += fmt::format("version ............: {}\n", m_self.version);
header += fmt::format("mode ...............: {:#04x}\n", m_self.mode);
header += fmt::format("endian .............: {}\n", m_self.endian);
header += fmt::format("attributes .........: {:#04x}\n", m_self.attributes);
header += fmt::format("category ...........: {:#04x}\n", m_self.category);
header += fmt::format("program_type........: {:#04x}\n", m_self.program_type);
header += fmt::format("padding1 ...........: {:#06x}\n", m_self.padding1);
header += fmt::format("padding1 ...........: {}\n", log_hex_full(m_self.padding1));
header += fmt::format("header size ........: {}\n", m_self.header_size);
header += fmt::format("meta size ..........: {}\n", m_self.meta_size);
header += fmt::format("file size ..........: {}\n", m_self.file_size);
header += fmt::format("padding2 ...........: {:#010x}\n", m_self.padding2);
header += fmt::format("padding2 ...........: {}\n", log_hex_full(m_self.padding2));
header += fmt::format("segment count ......: {}\n", m_self.segment_count);
header += fmt::format("unknown 1A .........: {:#06x}\n", m_self.unknown1A);
header += fmt::format("padding3 ...........: {:#010x}\n", m_self.padding3);
header += fmt::format("unknown 1A .........: {}\n", log_hex_full(m_self.unknown1A));
header += fmt::format("padding3 ...........: {}\n", log_hex_full(m_self.padding3));
return header;
}
@ -372,10 +319,10 @@ std::string Elf::ElfHeaderStr() {
header += fmt::format("type ............: {}\n", static_cast<u32>(m_elf_header.e_type));
header += fmt::format("machine ..........: {}\n", static_cast<u32>(m_elf_header.e_machine));
header += fmt::format("version ..........: {}\n", static_cast<u32>(m_elf_header.e_version));
header += fmt::format("entry ............: {:#018x}\n", m_elf_header.e_entry);
header += fmt::format("phoff ............: {:#018x}\n", m_elf_header.e_phoff);
header += fmt::format("shoff ............: {:#018x}\n", m_elf_header.e_shoff);
header += fmt::format("flags ............: {:#010x}\n", m_elf_header.e_flags);
header += fmt::format("entry ............: {}\n", log_hex_full(m_elf_header.e_entry));
header += fmt::format("phoff ............: {}\n", log_hex_full(m_elf_header.e_phoff));
header += fmt::format("shoff ............: {}\n", log_hex_full(m_elf_header.e_shoff));
header += fmt::format("flags ............: {}\n", log_hex_full(m_elf_header.e_flags));
header += fmt::format("ehsize ...........: {}\n", m_elf_header.e_ehsize);
header += fmt::format("phentsize ........: {}\n", m_elf_header.e_phentsize);
header += fmt::format("phnum ............: {}\n", m_elf_header.e_phnum);
@ -422,13 +369,13 @@ std::string Elf::ElfPheaderFlagsStr(u32 flags) {
std::string Elf::ElfPHeaderStr(u16 no) {
std::string header = fmt::format("====== PROGRAM HEADER {} ========\n", no);
header += fmt::format("p_type ....: {}\n", ElfPheaderTypeStr(m_elf_phdr[no].p_type));
header += fmt::format("p_flags ...: {:#010x}\n", static_cast<u32>(m_elf_phdr[no].p_flags));
header += fmt::format("p_offset ..: {:#018x}\n", m_elf_phdr[no].p_offset);
header += fmt::format("p_vaddr ...: {:#018x}\n", m_elf_phdr[no].p_vaddr);
header += fmt::format("p_paddr ...: {:#018x}\n", m_elf_phdr[no].p_paddr);
header += fmt::format("p_filesz ..: {:#018x}\n", m_elf_phdr[no].p_filesz);
header += fmt::format("p_memsz ...: {:#018x}\n", m_elf_phdr[no].p_memsz);
header += fmt::format("p_align ...: {:#018x}\n", m_elf_phdr[no].p_align);
header += fmt::format("p_flags ...: {}\n", log_hex_full(static_cast<u32>(m_elf_phdr[no].p_flags)));
header += fmt::format("p_offset ..: {}\n", log_hex_full(m_elf_phdr[no].p_offset));
header += fmt::format("p_vaddr ...: {}\n", log_hex_full(m_elf_phdr[no].p_vaddr));
header += fmt::format("p_paddr ...: {}\n", log_hex_full(m_elf_phdr[no].p_paddr));
header += fmt::format("p_filesz ..: {}\n", log_hex_full(m_elf_phdr[no].p_filesz));
header += fmt::format("p_memsz ...: {}\n", log_hex_full(m_elf_phdr[no].p_memsz));
header += fmt::format("p_align ...: {}\n", log_hex_full(m_elf_phdr[no].p_align));
return header;
}