Introduce TID to Logger + Fix VMM Bug + Fix NSO Backtrace + Improve Logger

This commit is contained in:
◱ PixelyIon 2020-10-23 23:53:16 +05:30 committed by ◱ PixelyIon
parent 39f0345ac7
commit 779884edcf
11 changed files with 117 additions and 99 deletions

View File

@ -151,7 +151,7 @@ namespace skyline {
character = '\\'; character = '\\';
std::lock_guard guard(mtx); std::lock_guard guard(mtx);
logFile << "1|" << levelCharacter[static_cast<u8>(level)] << "|" << str << "\n"; logFile << "1|" << levelCharacter[static_cast<u8>(level)] << '|' << std::dec << pthread_self() << '|' << str << '\n';
} }
DeviceState::DeviceState(kernel::OS *os, std::shared_ptr<kernel::type::KProcess> &process, std::shared_ptr<JvmManager> jvmManager, std::shared_ptr<Settings> settings, std::shared_ptr<Logger> logger) DeviceState::DeviceState(kernel::OS *os, std::shared_ptr<kernel::type::KProcess> &process, std::shared_ptr<JvmManager> jvmManager, std::shared_ptr<Settings> settings, std::shared_ptr<Logger> logger)

View File

@ -261,7 +261,7 @@ namespace skyline::kernel::svc {
state.logger->Debug("svcStartThread: Starting thread: 0x{:X}, PID: {}", handle, thread->id); state.logger->Debug("svcStartThread: Starting thread: 0x{:X}, PID: {}", handle, thread->id);
thread->Start(); thread->Start();
state.ctx->gpr.w0 = Result{}; state.ctx->gpr.w0 = Result{};
} catch (const std::exception &) { } catch (const std::out_of_range &) {
state.logger->Warn("svcStartThread: 'handle' invalid: 0x{:X}", handle); state.logger->Warn("svcStartThread: 'handle' invalid: 0x{:X}", handle);
state.ctx->gpr.w0 = result::InvalidHandle; state.ctx->gpr.w0 = result::InvalidHandle;
} }
@ -301,7 +301,7 @@ namespace skyline::kernel::svc {
state.ctx->gpr.w1 = priority; state.ctx->gpr.w1 = priority;
state.ctx->gpr.w0 = Result{}; state.ctx->gpr.w0 = Result{};
} catch (const std::exception &) { } catch (const std::out_of_range &) {
state.logger->Warn("svcGetThreadPriority: 'handle' invalid: 0x{:X}", handle); state.logger->Warn("svcGetThreadPriority: 'handle' invalid: 0x{:X}", handle);
state.ctx->gpr.w0 = result::InvalidHandle; state.ctx->gpr.w0 = result::InvalidHandle;
} }
@ -320,7 +320,7 @@ namespace skyline::kernel::svc {
state.logger->Debug("svcSetThreadPriority: Setting thread priority to {}", thread->id, priority); state.logger->Debug("svcSetThreadPriority: Setting thread priority to {}", thread->id, priority);
thread->UpdatePriority(static_cast<u8>(priority)); thread->UpdatePriority(static_cast<u8>(priority));
state.ctx->gpr.w0 = Result{}; state.ctx->gpr.w0 = Result{};
} catch (const std::exception &) { } catch (const std::out_of_range &) {
state.logger->Warn("svcSetThreadPriority: 'handle' invalid: 0x{:X}", handle); state.logger->Warn("svcSetThreadPriority: 'handle' invalid: 0x{:X}", handle);
state.ctx->gpr.w0 = result::InvalidHandle; state.ctx->gpr.w0 = result::InvalidHandle;
} }
@ -337,7 +337,7 @@ namespace skyline::kernel::svc {
state.ctx->gpr.x2 = affinityMask.to_ullong(); state.ctx->gpr.x2 = affinityMask.to_ullong();
state.ctx->gpr.w1 = idealCore; state.ctx->gpr.w1 = idealCore;
state.ctx->gpr.w0 = Result{}; state.ctx->gpr.w0 = Result{};
} catch (const std::exception &) { } catch (const std::out_of_range &) {
state.logger->Warn("svcGetThreadCoreMask: 'handle' invalid: 0x{:X}", handle); state.logger->Warn("svcGetThreadCoreMask: 'handle' invalid: 0x{:X}", handle);
state.ctx->gpr.w0 = result::InvalidHandle; state.ctx->gpr.w0 = result::InvalidHandle;
} }
@ -371,7 +371,7 @@ namespace skyline::kernel::svc {
thread->affinityMask = affinityMask; thread->affinityMask = affinityMask;
state.ctx->gpr.w0 = Result{}; state.ctx->gpr.w0 = Result{};
} catch (const std::exception &) { } catch (const std::out_of_range &) {
state.logger->Warn("svcSetThreadCoreMask: 'handle' invalid: 0x{:X}", handle); state.logger->Warn("svcSetThreadCoreMask: 'handle' invalid: 0x{:X}", handle);
state.ctx->gpr.w0 = result::InvalidHandle; state.ctx->gpr.w0 = result::InvalidHandle;
} }
@ -418,7 +418,7 @@ namespace skyline::kernel::svc {
object->Map(pointer, size, permission); object->Map(pointer, size, permission);
state.ctx->gpr.w0 = Result{}; state.ctx->gpr.w0 = Result{};
} catch (const std::exception &) { } catch (const std::out_of_range &) {
state.logger->Warn("svcMapSharedMemory: 'handle' invalid: 0x{:X}", static_cast<u32>(state.ctx->gpr.w0)); state.logger->Warn("svcMapSharedMemory: 'handle' invalid: 0x{:X}", static_cast<u32>(state.ctx->gpr.w0));
state.ctx->gpr.w0 = result::InvalidHandle; state.ctx->gpr.w0 = result::InvalidHandle;
} }
@ -459,7 +459,7 @@ namespace skyline::kernel::svc {
state.process->CloseHandle(handle); state.process->CloseHandle(handle);
state.logger->Debug("svcCloseHandle: Closing handle: 0x{:X}", handle); state.logger->Debug("svcCloseHandle: Closing handle: 0x{:X}", handle);
state.ctx->gpr.w0 = Result{}; state.ctx->gpr.w0 = Result{};
} catch (const std::exception &) { } catch (const std::out_of_range &) {
state.logger->Warn("svcCloseHandle: 'handle' invalid: 0x{:X}", handle); state.logger->Warn("svcCloseHandle: 'handle' invalid: 0x{:X}", handle);
state.ctx->gpr.w0 = result::InvalidHandle; state.ctx->gpr.w0 = result::InvalidHandle;
} }
@ -560,7 +560,7 @@ namespace skyline::kernel::svc {
void CancelSynchronization(const DeviceState &state) { void CancelSynchronization(const DeviceState &state) {
try { try {
state.process->GetHandle<type::KThread>(state.ctx->gpr.w0)->cancelSync = true; state.process->GetHandle<type::KThread>(state.ctx->gpr.w0)->cancelSync = true;
} catch (const std::exception &) { } catch (const std::out_of_range &) {
state.logger->Warn("svcCancelSynchronization: 'handle' invalid: 0x{:X}", static_cast<u32>(state.ctx->gpr.w0)); state.logger->Warn("svcCancelSynchronization: 'handle' invalid: 0x{:X}", static_cast<u32>(state.ctx->gpr.w0));
state.ctx->gpr.w0 = result::InvalidHandle; state.ctx->gpr.w0 = result::InvalidHandle;
} }
@ -708,34 +708,34 @@ namespace skyline::kernel::svc {
void GetInfo(const DeviceState &state) { void GetInfo(const DeviceState &state) {
enum class InfoState : u32 { enum class InfoState : u32 {
// 1.0.0+ // 1.0.0+
AllowedCpuIdBitmask = 0x0, AllowedCpuIdBitmask = 0,
AllowedThreadPriorityMask = 0x1, AllowedThreadPriorityMask = 1,
AliasRegionBaseAddr = 0x2, AliasRegionBaseAddr = 2,
AliasRegionSize = 0x3, AliasRegionSize = 3,
HeapRegionBaseAddr = 0x4, HeapRegionBaseAddr = 4,
HeapRegionSize = 0x5, HeapRegionSize = 5,
TotalMemoryAvailable = 0x6, TotalMemoryAvailable = 6,
TotalMemoryUsage = 0x7, TotalMemoryUsage = 7,
IsCurrentProcessBeingDebugged = 0x8, IsCurrentProcessBeingDebugged = 8,
ResourceLimit = 0x9, ResourceLimit = 9,
IdleTickCount = 0xA, IdleTickCount = 10,
RandomEntropy = 0xB, RandomEntropy = 11,
// 2.0.0+ // 2.0.0+
AddressSpaceBaseAddr = 0xC, AddressSpaceBaseAddr = 12,
AddressSpaceSize = 0xD, AddressSpaceSize = 13,
StackRegionBaseAddr = 0xE, StackRegionBaseAddr = 14,
StackRegionSize = 0xF, StackRegionSize = 15,
// 3.0.0+ // 3.0.0+
TotalSystemResourceAvailable = 0x10, TotalSystemResourceAvailable = 16,
TotalSystemResourceUsage = 0x11, TotalSystemResourceUsage = 17,
TitleId = 0x12, TitleId = 18,
// 4.0.0+ // 4.0.0+
PrivilegedProcessId = 0x13, PrivilegedProcessId = 19,
// 5.0.0+ // 5.0.0+
UserExceptionContextAddr = 0x14, UserExceptionContextAddr = 20,
// 6.0.0+ // 6.0.0+
TotalMemoryAvailableWithoutSystemResource = 0x15, TotalMemoryAvailableWithoutSystemResource = 21,
TotalMemoryUsageWithoutSystemResource = 0x16, TotalMemoryUsageWithoutSystemResource = 22,
}; };
InfoState info{static_cast<u32>(state.ctx->gpr.w1)}; InfoState info{static_cast<u32>(state.ctx->gpr.w1)};

View File

@ -163,7 +163,7 @@ namespace skyline {
else else
throw exception("Tried to get kernel object (0x{:X}) with different type: {} when object is {}", handle, objectType, item->objectType); throw exception("Tried to get kernel object (0x{:X}) with different type: {} when object is {}", handle, objectType, item->objectType);
} catch (std::out_of_range) { } catch (std::out_of_range) {
throw exception("GetHandle was called with an invalid handle: 0x{:X}", handle); throw std::out_of_range(fmt::format("GetHandle was called with an invalid handle: 0x{:X}", handle));
} }
} }

View File

@ -22,7 +22,7 @@ namespace skyline::kernel::type {
constexpr bool Valid() { constexpr bool Valid() {
return ptr && size; return ptr && size;
} }
} kernel, guest; } kernel, guest{};
KSharedMemory(const DeviceState &state, size_t size, memory::MemoryState memState = memory::states::SharedMemory, KType type = KType::KSharedMemory); KSharedMemory(const DeviceState &state, size_t size, memory::MemoryState memState = memory::states::SharedMemory, KType type = KType::KSharedMemory);

View File

@ -29,7 +29,7 @@ namespace skyline::loader {
process->NewHandle<kernel::type::KPrivateMemory>(base + patch.size + executable.text.offset, textSize, memory::Permission{true, false, true}, memory::states::CodeStatic); // R-X process->NewHandle<kernel::type::KPrivateMemory>(base + patch.size + executable.text.offset, textSize, memory::Permission{true, false, true}, memory::states::CodeStatic); // R-X
state.logger->Debug("Successfully mapped section .text @ 0x{:X}, Size = 0x{:X}", base + patch.size + executable.text.offset, textSize); state.logger->Debug("Successfully mapped section .text @ 0x{:X}, Size = 0x{:X}", base + patch.size + executable.text.offset, textSize);
process->NewHandle<kernel::type::KPrivateMemory>(base + patch.size + executable.ro.offset, roSize, memory::Permission{true, false, false}, memory::states::CodeReadOnly); // R-- process->NewHandle<kernel::type::KPrivateMemory>(base + patch.size + executable.ro.offset, roSize, memory::Permission{true, false, false}, memory::states::CodeStatic); // R--
state.logger->Debug("Successfully mapped section .rodata @ 0x{:X}, Size = 0x{:X}", base + patch.size + executable.ro.offset, roSize); state.logger->Debug("Successfully mapped section .rodata @ 0x{:X}, Size = 0x{:X}", base + patch.size + executable.ro.offset, roSize);
process->NewHandle<kernel::type::KPrivateMemory>(base + patch.size + executable.data.offset, dataSize, memory::Permission{true, true, false}, memory::states::CodeMutable); // RW- process->NewHandle<kernel::type::KPrivateMemory>(base + patch.size + executable.data.offset, dataSize, memory::Permission{true, true, false}, memory::states::CodeMutable); // RW-

View File

@ -43,7 +43,7 @@ namespace skyline::service::audio::IAudioRenderer {
if (input.format == skyline::audio::AudioFormat::ADPCM) { if (input.format == skyline::audio::AudioFormat::ADPCM) {
std::vector<std::array<i16, 2>> adpcmCoefficients(input.adpcmCoeffsSize / (sizeof(u16) * 2)); std::vector<std::array<i16, 2>> adpcmCoefficients(input.adpcmCoeffsSize / (sizeof(u16) * 2));
span(adpcmCoefficients).copy_from(span(input.adpcmCoeffs, input.adpcmCoeffsSize)); span(adpcmCoefficients).copy_from(span(input.adpcmCoeffs, input.adpcmCoeffsSize / sizeof(u32)));
adpcmDecoder = skyline::audio::AdpcmDecoder(adpcmCoefficients); adpcmDecoder = skyline::audio::AdpcmDecoder(adpcmCoefficients);
} }

View File

@ -6,31 +6,6 @@
namespace skyline::service::lm { namespace skyline::service::lm {
ILogger::ILogger(const DeviceState &state, ServiceManager &manager) : BaseService(state, manager) {} ILogger::ILogger(const DeviceState &state, ServiceManager &manager) : BaseService(state, manager) {}
std::string ILogger::GetFieldName(LogFieldType type) {
switch (type) {
case LogFieldType::Message:
return "Message";
case LogFieldType::Line:
return "Line";
case LogFieldType::Filename:
return "Filename";
case LogFieldType::Function:
return "Function";
case LogFieldType::Module:
return "Module";
case LogFieldType::Thread:
return "Thread";
case LogFieldType::DropCount:
return "DropCount";
case LogFieldType::Time:
return "Time";
case LogFieldType::ProgramName:
return "ProgramName";
default:
return "";
}
}
Result ILogger::Log(type::KSession &session, ipc::IpcRequest &request, ipc::IpcResponse &response) { Result ILogger::Log(type::KSession &session, ipc::IpcRequest &request, ipc::IpcResponse &response) {
struct Data { struct Data {
u64 pid; u64 pid;
@ -41,8 +16,17 @@ namespace skyline::service::lm {
u32 payloadLength; u32 payloadLength;
} &data = request.inputBuf.at(0).as<Data>(); } &data = request.inputBuf.at(0).as<Data>();
std::ostringstream logMessage; struct LogMessage {
logMessage << "Guest log:"; std::string_view message;
u32 line;
std::string_view filename;
std::string_view function;
std::string_view module;
std::string_view thread;
u64 dropCount;
u64 time;
std::string_view program;
} logMessage{};
u64 offset{sizeof(Data)}; u64 offset{sizeof(Data)};
while (offset < request.inputBuf[0].size()) { while (offset < request.inputBuf[0].size()) {
@ -50,50 +34,90 @@ namespace skyline::service::lm {
auto length{request.inputBuf[0].subspan(offset++).as<u8>()}; auto length{request.inputBuf[0].subspan(offset++).as<u8>()};
auto object{request.inputBuf[0].subspan(offset, length)}; auto object{request.inputBuf[0].subspan(offset, length)};
logMessage << " ";
switch (fieldType) { switch (fieldType) {
case LogFieldType::Start: case LogFieldType::Start:
offset += length; offset += length;
continue; continue;
case LogFieldType::Line:
logMessage << GetFieldName(fieldType) << ": " << object.as<u32>();
offset += sizeof(u32);
continue;
case LogFieldType::DropCount:
logMessage << GetFieldName(fieldType) << ": " << object.as<u64>();
offset += sizeof(u64);
continue;
case LogFieldType::Time:
logMessage << GetFieldName(fieldType) << ": " << object.as<u64>() << "s";
offset += sizeof(u64);
continue;
case LogFieldType::Stop: case LogFieldType::Stop:
break; break;
default: case LogFieldType::Message:
logMessage << GetFieldName(fieldType) << ": " << object.as_string(); logMessage.message = object.as_string();
offset += length;
continue;
case LogFieldType::Line:
logMessage.line = object.as<u32>();
offset += sizeof(u32);
continue;
case LogFieldType::Filename: {
logMessage.filename = object.as_string();
auto position{logMessage.filename.find_last_of('/')};
logMessage.filename.remove_prefix(position != std::string::npos ? position + 1 : 0);
offset += length;
continue;
}
case LogFieldType::Function:
logMessage.function = object.as_string();
offset += length;
continue;
case LogFieldType::Module:
logMessage.module = object.as_string();
offset += length;
continue;
case LogFieldType::Thread:
logMessage.thread = object.as_string();
offset += length;
continue;
case LogFieldType::DropCount:
logMessage.dropCount = object.as<u64>();
offset += sizeof(u64);
continue;
case LogFieldType::Time:
logMessage.time = object.as<u64>();
offset += sizeof(u64);
continue;
case LogFieldType::ProgramName:
logMessage.program = object.as_string();
offset += length; offset += length;
continue; continue;
} }
break; break;
} }
Logger::LogLevel hostLevel{[&data]() {
switch (data.level) { switch (data.level) {
case LogLevel::Trace: case LogLevel::Trace:
state.logger->Debug("{}", logMessage.str()); return Logger::LogLevel::Debug;
break;
case LogLevel::Info: case LogLevel::Info:
state.logger->Info("{}", logMessage.str()); return Logger::LogLevel::Info;
break;
case LogLevel::Warning: case LogLevel::Warning:
state.logger->Warn("{}", logMessage.str()); return Logger::LogLevel::Warn;
break;
case LogLevel::Error: case LogLevel::Error:
case LogLevel::Critical: case LogLevel::Critical:
state.logger->Error("{}", logMessage.str()); return Logger::LogLevel::Error;
break;
} }
}()};
std::ostringstream message;
if (!logMessage.filename.empty())
message << logMessage.filename << ':';
if (logMessage.line)
message << 'L' << std::dec << logMessage.line << ':';
if (!logMessage.program.empty())
message << logMessage.program << ':';
if (!logMessage.module.empty())
message << logMessage.module << ':';
if (!logMessage.function.empty())
message << logMessage.function << "():";
if (!logMessage.thread.empty())
message << logMessage.thread << ':';
if (logMessage.time)
message << logMessage.time << "s:";
if (!logMessage.message.empty())
message << ' ' << logMessage.message;
if (logMessage.dropCount)
message << " (Dropped Messages: " << logMessage.time << ')';
state.logger->Write(hostLevel, message.str());
return {}; return {};
} }

View File

@ -34,13 +34,6 @@ namespace skyline::service::lm {
Critical, Critical,
}; };
/**
* @brief Obtains a string containing the name of the given field type
* @param type The field type to return the name of
* @return The name of the given field type
*/
std::string GetFieldName(LogFieldType type);
public: public:
ILogger(const DeviceState &state, ServiceManager &manager); ILogger(const DeviceState &state, ServiceManager &manager);

View File

@ -80,7 +80,8 @@ namespace skyline::service {
SERVICE_CASE(ssl::ISslService, "ssl") SERVICE_CASE(ssl::ISslService, "ssl")
SERVICE_CASE(prepo::IPrepoService, "prepo:u") SERVICE_CASE(prepo::IPrepoService, "prepo:u")
default: default:
throw exception("CreateService called with an unknown service name: {}", name); std::string_view nameString(span(reinterpret_cast<char *>(&name), sizeof(name)).as_string(true));
throw std::out_of_range(fmt::format("CreateService called with an unknown service name: {}", nameString));
} }
} }

View File

@ -18,11 +18,11 @@ namespace skyline::service::sm {
try { try {
manager.NewService(name, session, response); manager.NewService(name, session, response);
return {};
} catch (std::out_of_range &) { } catch (std::out_of_range &) {
std::string_view stringName(reinterpret_cast<char *>(&name), sizeof(u64)); std::string_view stringName(reinterpret_cast<char *>(&name), sizeof(u64));
state.logger->Warn("Service has not been implemented: \"{}\"", stringName); state.logger->Warn("Service has not been implemented: \"{}\"", stringName);
return result::InvalidServiceName;
} }
return {};
} }
} }

View File

@ -74,7 +74,7 @@ class LogActivity : AppCompatActivity() {
val level = logMeta[1].toInt() val level = logMeta[1].toInt()
if (level > logLevel) return@forEachLine if (level > logLevel) return@forEachLine
adapter.addItem(LogViewItem(compact, logMeta[2].replace('\\', '\n'), logLevels[level])) adapter.addItem(LogViewItem(compact, "(" + logMeta[2] + ") " + logMeta[3].replace('\\', '\n'), logLevels[level]))
} else { } else {
adapter.addItem(HeaderViewItem(logMeta[1])) adapter.addItem(HeaderViewItem(logMeta[1]))
} }