svc: Use the current process' handle table for retrieving the process instance to act upon

The kernel uses the handle table of the current process to retrieve the
process that should be used to retrieve certain information. To someone
not familiar with the kernel, this might raise the question of "Ok,
sounds nice, but doesn't this make it impossible to retrieve information
about the current process?".

No, it doesn't, because HandleTable instances in the kernel have the
notion of a "pseudo-handle", where certain values allow the kernel to
lookup objects outside of a given handle table. Currently, there's only
a pseudo-handle for the current process (0xFFFF8001) and a pseudo-handle
for the current thread (0xFFFF8000), so to retrieve the current process,
one would just pass 0xFFFF8001 into svcGetInfo.

The lookup itself in the handle table would be something like:

template <typename T>
T* Lookup(Handle handle) {
    if (handle == PSEUDO_HANDLE_CURRENT_PROCESS) {
        return CurrentProcess();
    }

    if (handle == PSUEDO_HANDLE_CURRENT_THREAD) {
        return CurrentThread();
    }

    return static_cast<T*>(&objects[handle]);
}

which, as is shown, allows accessing the current process or current
thread, even if those two objects aren't actually within the HandleTable
instance.

src/core/file_sys/control_metadata.cpp

@@ -8,13 +8,23 @@
 
 namespace FileSys {
 
-const std::array<const char*, 15> LANGUAGE_NAMES = {
-    "AmericanEnglish", "BritishEnglish", "Japanese",
-    "French",          "German",         "LatinAmericanSpanish",
-    "Spanish",         "Italian",        "Dutch",
-    "CanadianFrench",  "Portugese",      "Russian",
-    "Korean",          "Taiwanese",      "Chinese",
-};
+const std::array<const char*, 15> LANGUAGE_NAMES{{
+    "AmericanEnglish",
+    "BritishEnglish",
+    "Japanese",
+    "French",
+    "German",
+    "LatinAmericanSpanish",
+    "Spanish",
+    "Italian",
+    "Dutch",
+    "CanadianFrench",
+    "Portuguese",
+    "Russian",
+    "Korean",
+    "Taiwanese",
+    "Chinese",
+}};
 
 std::string LanguageEntry::GetApplicationName() const {
     return Common::StringFromFixedZeroTerminatedBuffer(application_name.data(),

src/core/file_sys/registered_cache.cpp

@@ -381,22 +381,22 @@ std::vector<RegisteredCacheEntry> RegisteredCache::ListEntriesFilter(
     return out;
 }
 
-static std::shared_ptr<NCA> GetNCAFromNSPForID(std::shared_ptr<NSP> nsp, const NcaID& id) {
-    const auto file = nsp->GetFile(fmt::format("{}.nca", Common::HexArrayToString(id, false)));
+static std::shared_ptr<NCA> GetNCAFromNSPForID(const NSP& nsp, const NcaID& id) {
+    const auto file = nsp.GetFile(fmt::format("{}.nca", Common::HexArrayToString(id, false)));
     if (file == nullptr)
         return nullptr;
     return std::make_shared<NCA>(file);
 }
 
-InstallResult RegisteredCache::InstallEntry(std::shared_ptr<XCI> xci, bool overwrite_if_exists,
+InstallResult RegisteredCache::InstallEntry(const XCI& xci, bool overwrite_if_exists,
                                             const VfsCopyFunction& copy) {
-    return InstallEntry(xci->GetSecurePartitionNSP(), overwrite_if_exists, copy);
+    return InstallEntry(*xci.GetSecurePartitionNSP(), overwrite_if_exists, copy);
 }
 
-InstallResult RegisteredCache::InstallEntry(std::shared_ptr<NSP> nsp, bool overwrite_if_exists,
+InstallResult RegisteredCache::InstallEntry(const NSP& nsp, bool overwrite_if_exists,
                                             const VfsCopyFunction& copy) {
-    const auto& ncas = nsp->GetNCAsCollapsed();
-    const auto& meta_iter = std::find_if(ncas.begin(), ncas.end(), [](std::shared_ptr<NCA> nca) {
+    const auto ncas = nsp.GetNCAsCollapsed();
+    const auto meta_iter = std::find_if(ncas.begin(), ncas.end(), [](const auto& nca) {
         return nca->GetType() == NCAContentType::Meta;
     });
 
@@ -410,7 +410,7 @@ InstallResult RegisteredCache::InstallEntry(std::shared_ptr<NSP> nsp, bool overw
     const auto meta_id_raw = (*meta_iter)->GetName().substr(0, 32);
     const auto meta_id = Common::HexStringToArray<16>(meta_id_raw);
 
-    const auto res = RawInstallNCA(*meta_iter, copy, overwrite_if_exists, meta_id);
+    const auto res = RawInstallNCA(**meta_iter, copy, overwrite_if_exists, meta_id);
     if (res != InstallResult::Success)
         return res;
 
@@ -422,7 +422,7 @@ InstallResult RegisteredCache::InstallEntry(std::shared_ptr<NSP> nsp, bool overw
         const auto nca = GetNCAFromNSPForID(nsp, record.nca_id);
         if (nca == nullptr)
             return InstallResult::ErrorCopyFailed;
-        const auto res2 = RawInstallNCA(nca, copy, overwrite_if_exists, record.nca_id);
+        const auto res2 = RawInstallNCA(*nca, copy, overwrite_if_exists, record.nca_id);
         if (res2 != InstallResult::Success)
             return res2;
     }
@@ -431,21 +431,21 @@ InstallResult RegisteredCache::InstallEntry(std::shared_ptr<NSP> nsp, bool overw
     return InstallResult::Success;
 }
 
-InstallResult RegisteredCache::InstallEntry(std::shared_ptr<NCA> nca, TitleType type,
+InstallResult RegisteredCache::InstallEntry(const NCA& nca, TitleType type,
                                             bool overwrite_if_exists, const VfsCopyFunction& copy) {
     CNMTHeader header{
-        nca->GetTitleId(), ///< Title ID
-        0,                 ///< Ignore/Default title version
-        type,              ///< Type
-        {},                ///< Padding
-        0x10,              ///< Default table offset
-        1,                 ///< 1 Content Entry
-        0,                 ///< No Meta Entries
-        {},                ///< Padding
+        nca.GetTitleId(), ///< Title ID
+        0,                ///< Ignore/Default title version
+        type,             ///< Type
+        {},               ///< Padding
+        0x10,             ///< Default table offset
+        1,                ///< 1 Content Entry
+        0,                ///< No Meta Entries
+        {},               ///< Padding
     };
     OptionalHeader opt_header{0, 0};
-    ContentRecord c_rec{{}, {}, {}, GetCRTypeFromNCAType(nca->GetType()), {}};
-    const auto& data = nca->GetBaseFile()->ReadBytes(0x100000);
+    ContentRecord c_rec{{}, {}, {}, GetCRTypeFromNCAType(nca.GetType()), {}};
+    const auto& data = nca.GetBaseFile()->ReadBytes(0x100000);
     mbedtls_sha256(data.data(), data.size(), c_rec.hash.data(), 0);
     memcpy(&c_rec.nca_id, &c_rec.hash, 16);
     const CNMT new_cnmt(header, opt_header, {c_rec}, {});
@@ -454,10 +454,10 @@ InstallResult RegisteredCache::InstallEntry(std::shared_ptr<NCA> nca, TitleType
     return RawInstallNCA(nca, copy, overwrite_if_exists, c_rec.nca_id);
 }
 
-InstallResult RegisteredCache::RawInstallNCA(std::shared_ptr<NCA> nca, const VfsCopyFunction& copy,
+InstallResult RegisteredCache::RawInstallNCA(const NCA& nca, const VfsCopyFunction& copy,
                                              bool overwrite_if_exists,
                                              std::optional<NcaID> override_id) {
-    const auto in = nca->GetBaseFile();
+    const auto in = nca.GetBaseFile();
     Core::Crypto::SHA256Hash hash{};
 
     // Calculate NcaID

src/core/file_sys/registered_cache.h

@@ -6,7 +6,6 @@
 
 #include <array>
 #include <functional>
-#include <map>
 #include <memory>
 #include <string>
 #include <vector>
@@ -104,17 +103,16 @@ public:
 
     // Raw copies all the ncas from the xci/nsp to the csache. Does some quick checks to make sure
     // there is a meta NCA and all of them are accessible.
-    InstallResult InstallEntry(std::shared_ptr<XCI> xci, bool overwrite_if_exists = false,
+    InstallResult InstallEntry(const XCI& xci, bool overwrite_if_exists = false,
                                const VfsCopyFunction& copy = &VfsRawCopy);
-    InstallResult InstallEntry(std::shared_ptr<NSP> nsp, bool overwrite_if_exists = false,
+    InstallResult InstallEntry(const NSP& nsp, bool overwrite_if_exists = false,
                                const VfsCopyFunction& copy = &VfsRawCopy);
 
     // Due to the fact that we must use Meta-type NCAs to determine the existance of files, this
     // poses quite a challenge. Instead of creating a new meta NCA for this file, yuzu will create a
     // dir inside the NAND called 'yuzu_meta' and store the raw CNMT there.
     // TODO(DarkLordZach): Author real meta-type NCAs and install those.
-    InstallResult InstallEntry(std::shared_ptr<NCA> nca, TitleType type,
-                               bool overwrite_if_exists = false,
+    InstallResult InstallEntry(const NCA& nca, TitleType type, bool overwrite_if_exists = false,
                                const VfsCopyFunction& copy = &VfsRawCopy);
 
 private:
@@ -128,7 +126,7 @@ private:
     std::optional<NcaID> GetNcaIDFromMetadata(u64 title_id, ContentRecordType type) const;
     VirtualFile GetFileAtID(NcaID id) const;
     VirtualFile OpenFileOrDirectoryConcat(const VirtualDir& dir, std::string_view path) const;
-    InstallResult RawInstallNCA(std::shared_ptr<NCA> nca, const VfsCopyFunction& copy,
+    InstallResult RawInstallNCA(const NCA& nca, const VfsCopyFunction& copy,
                                 bool overwrite_if_exists, std::optional<NcaID> override_id = {});
     bool RawInstallYuzuMeta(const CNMT& cnmt);
 

src/core/hle/kernel/svc.cpp

@@ -63,43 +63,77 @@ bool IsInsideNewMapRegion(const VMManager& vm, VAddr address, u64 size) {
                                 vm.GetNewMapRegionEndAddress());
 }
 
+// 8 GiB
+constexpr u64 MAIN_MEMORY_SIZE = 0x200000000;
+
 // Helper function that performs the common sanity checks for svcMapMemory
 // and svcUnmapMemory. This is doable, as both functions perform their sanitizing
 // in the same order.
 ResultCode MapUnmapMemorySanityChecks(const VMManager& vm_manager, VAddr dst_addr, VAddr src_addr,
                                       u64 size) {
-    if (!Common::Is4KBAligned(dst_addr) || !Common::Is4KBAligned(src_addr)) {
+    if (!Common::Is4KBAligned(dst_addr)) {
+        LOG_ERROR(Kernel_SVC, "Destination address is not aligned to 4KB, 0x{:016X}", dst_addr);
         return ERR_INVALID_ADDRESS;
     }
 
-    if (size == 0 || !Common::Is4KBAligned(size)) {
+    if (!Common::Is4KBAligned(src_addr)) {
+        LOG_ERROR(Kernel_SVC, "Source address is not aligned to 4KB, 0x{:016X}", src_addr);
+        return ERR_INVALID_SIZE;
+    }
+
+    if (size == 0) {
+        LOG_ERROR(Kernel_SVC, "Size is 0");
+        return ERR_INVALID_SIZE;
+    }
+
+    if (!Common::Is4KBAligned(size)) {
+        LOG_ERROR(Kernel_SVC, "Size is not aligned to 4KB, 0x{:016X}", size);
         return ERR_INVALID_SIZE;
     }
 
     if (!IsValidAddressRange(dst_addr, size)) {
+        LOG_ERROR(Kernel_SVC,
+                  "Destination is not a valid address range, addr=0x{:016X}, size=0x{:016X}",
+                  dst_addr, size);
         return ERR_INVALID_ADDRESS_STATE;
     }
 
     if (!IsValidAddressRange(src_addr, size)) {
+        LOG_ERROR(Kernel_SVC, "Source is not a valid address range, addr=0x{:016X}, size=0x{:016X}",
+                  src_addr, size);
         return ERR_INVALID_ADDRESS_STATE;
     }
 
     if (!IsInsideAddressSpace(vm_manager, src_addr, size)) {
+        LOG_ERROR(Kernel_SVC,
+                  "Source is not within the address space, addr=0x{:016X}, size=0x{:016X}",
+                  src_addr, size);
         return ERR_INVALID_ADDRESS_STATE;
     }
 
     if (!IsInsideNewMapRegion(vm_manager, dst_addr, size)) {
+        LOG_ERROR(Kernel_SVC,
+                  "Destination is not within the new map region, addr=0x{:016X}, size=0x{:016X}",
+                  dst_addr, size);
         return ERR_INVALID_MEMORY_RANGE;
     }
 
     const VAddr dst_end_address = dst_addr + size;
     if (dst_end_address > vm_manager.GetHeapRegionBaseAddress() &&
         vm_manager.GetHeapRegionEndAddress() > dst_addr) {
+        LOG_ERROR(Kernel_SVC,
+                  "Destination does not fit within the heap region, addr=0x{:016X}, "
+                  "size=0x{:016X}, end_addr=0x{:016X}",
+                  dst_addr, size, dst_end_address);
         return ERR_INVALID_MEMORY_RANGE;
     }
 
     if (dst_end_address > vm_manager.GetMapRegionBaseAddress() &&
         vm_manager.GetMapRegionEndAddress() > dst_addr) {
+        LOG_ERROR(Kernel_SVC,
+                  "Destination does not fit within the map region, addr=0x{:016X}, "
+                  "size=0x{:016X}, end_addr=0x{:016X}",
+                  dst_addr, size, dst_end_address);
         return ERR_INVALID_MEMORY_RANGE;
     }
 
@@ -143,8 +177,15 @@ ResultVal<s64> RetrieveResourceLimitValue(Handle resource_limit, u32 resource_ty
 static ResultCode SetHeapSize(VAddr* heap_addr, u64 heap_size) {
     LOG_TRACE(Kernel_SVC, "called, heap_size=0x{:X}", heap_size);
 
-    // Size must be a multiple of 0x200000 (2MB) and be equal to or less than 4GB.
-    if ((heap_size & 0xFFFFFFFE001FFFFF) != 0) {
+    // Size must be a multiple of 0x200000 (2MB) and be equal to or less than 8GB.
+    if ((heap_size % 0x200000) != 0) {
+        LOG_ERROR(Kernel_SVC, "The heap size is not a multiple of 2MB, heap_size=0x{:016X}",
+                  heap_size);
+        return ERR_INVALID_SIZE;
+    }
+
+    if (heap_size >= 0x200000000) {
+        LOG_ERROR(Kernel_SVC, "The heap size is not less than 8GB, heap_size=0x{:016X}", heap_size);
         return ERR_INVALID_SIZE;
     }
 
@@ -159,20 +200,31 @@ static ResultCode SetMemoryPermission(VAddr addr, u64 size, u32 prot) {
     LOG_TRACE(Kernel_SVC, "called, addr=0x{:X}, size=0x{:X}, prot=0x{:X}", addr, size, prot);
 
     if (!Common::Is4KBAligned(addr)) {
+        LOG_ERROR(Kernel_SVC, "Address is not aligned to 4KB, addr=0x{:016X}", addr);
         return ERR_INVALID_ADDRESS;
     }
 
-    if (size == 0 || !Common::Is4KBAligned(size)) {
+    if (size == 0) {
+        LOG_ERROR(Kernel_SVC, "Size is 0");
+        return ERR_INVALID_SIZE;
+    }
+
+    if (!Common::Is4KBAligned(size)) {
+        LOG_ERROR(Kernel_SVC, "Size is not aligned to 4KB, size=0x{:016X}", size);
         return ERR_INVALID_SIZE;
     }
 
     if (!IsValidAddressRange(addr, size)) {
+        LOG_ERROR(Kernel_SVC, "Region is not a valid address range, addr=0x{:016X}, size=0x{:016X}",
+                  addr, size);
         return ERR_INVALID_ADDRESS_STATE;
     }
 
     const auto permission = static_cast<MemoryPermission>(prot);
     if (permission != MemoryPermission::None && permission != MemoryPermission::Read &&
         permission != MemoryPermission::ReadWrite) {
+        LOG_ERROR(Kernel_SVC, "Invalid memory permission specified, Got memory permission=0x{:08X}",
+                  static_cast<u32>(permission));
         return ERR_INVALID_MEMORY_PERMISSIONS;
     }
 
@@ -180,11 +232,15 @@ static ResultCode SetMemoryPermission(VAddr addr, u64 size, u32 prot) {
     auto& vm_manager = current_process->VMManager();
 
     if (!IsInsideAddressSpace(vm_manager, addr, size)) {
+        LOG_ERROR(Kernel_SVC,
+                  "Source is not within the address space, addr=0x{:016X}, size=0x{:016X}", addr,
+                  size);
         return ERR_INVALID_ADDRESS_STATE;
     }
 
     const VMManager::VMAHandle iter = vm_manager.FindVMA(addr);
     if (iter == vm_manager.vma_map.end()) {
+        LOG_ERROR(Kernel_SVC, "Unable to find VMA for address=0x{:016X}", addr);
         return ERR_INVALID_ADDRESS_STATE;
     }
 
@@ -239,6 +295,9 @@ static ResultCode UnmapMemory(VAddr dst_addr, VAddr src_addr, u64 size) {
 /// Connect to an OS service given the port name, returns the handle to the port to out
 static ResultCode ConnectToNamedPort(Handle* out_handle, VAddr port_name_address) {
     if (!Memory::IsValidVirtualAddress(port_name_address)) {
+        LOG_ERROR(Kernel_SVC,
+                  "Port Name Address is not a valid virtual address, port_name_address=0x{:016X}",
+                  port_name_address);
         return ERR_NOT_FOUND;
     }
 
@@ -246,6 +305,8 @@ static ResultCode ConnectToNamedPort(Handle* out_handle, VAddr port_name_address
     // Read 1 char beyond the max allowed port name to detect names that are too long.
     std::string port_name = Memory::ReadCString(port_name_address, PortNameMaxLength + 1);
     if (port_name.size() > PortNameMaxLength) {
+        LOG_ERROR(Kernel_SVC, "Port name is too long, expected {} but got {}", PortNameMaxLength,
+                  port_name.size());
         return ERR_OUT_OF_RANGE;
     }
 
@@ -294,6 +355,7 @@ static ResultCode GetThreadId(u32* thread_id, Handle thread_handle) {
     const auto& handle_table = Core::CurrentProcess()->GetHandleTable();
     const SharedPtr<Thread> thread = handle_table.Get<Thread>(thread_handle);
     if (!thread) {
+        LOG_ERROR(Kernel_SVC, "Thread handle does not exist, handle=0x{:08X}", thread_handle);
         return ERR_INVALID_HANDLE;
     }
 
@@ -308,6 +370,8 @@ static ResultCode GetProcessId(u32* process_id, Handle process_handle) {
     const auto& handle_table = Core::CurrentProcess()->GetHandleTable();
     const SharedPtr<Process> process = handle_table.Get<Process>(process_handle);
     if (!process) {
+        LOG_ERROR(Kernel_SVC, "Process handle does not exist, process_handle=0x{:08X}",
+                  process_handle);
         return ERR_INVALID_HANDLE;
     }
 
@@ -337,12 +401,18 @@ static ResultCode WaitSynchronization(Handle* index, VAddr handles_address, u64
     LOG_TRACE(Kernel_SVC, "called handles_address=0x{:X}, handle_count={}, nano_seconds={}",
               handles_address, handle_count, nano_seconds);
 
-    if (!Memory::IsValidVirtualAddress(handles_address))
+    if (!Memory::IsValidVirtualAddress(handles_address)) {
+        LOG_ERROR(Kernel_SVC,
+                  "Handle address is not a valid virtual address, handle_address=0x{:016X}",
+                  handles_address);
         return ERR_INVALID_POINTER;
+    }
 
     static constexpr u64 MaxHandles = 0x40;
 
     if (handle_count > MaxHandles) {
+        LOG_ERROR(Kernel_SVC, "Handle count specified is too large, expected {} but got {}",
+                  MaxHandles, handle_count);
         return ERR_OUT_OF_RANGE;
     }
 
@@ -357,6 +427,7 @@ static ResultCode WaitSynchronization(Handle* index, VAddr handles_address, u64
         const auto object = handle_table.Get<WaitObject>(handle);
 
         if (object == nullptr) {
+            LOG_ERROR(Kernel_SVC, "Object is a nullptr");
             return ERR_INVALID_HANDLE;
         }
 
@@ -380,11 +451,13 @@ static ResultCode WaitSynchronization(Handle* index, VAddr handles_address, u64
 
     // If a timeout value of 0 was provided, just return the Timeout error code instead of
     // suspending the thread.
-    if (nano_seconds == 0)
+    if (nano_seconds == 0) {
         return RESULT_TIMEOUT;
+    }
 
-    for (auto& object : objects)
+    for (auto& object : objects) {
         object->AddWaitingThread(thread);
+    }
 
     thread->SetWaitObjects(std::move(objects));
     thread->SetStatus(ThreadStatus::WaitSynchAny);
@@ -405,6 +478,8 @@ static ResultCode CancelSynchronization(Handle thread_handle) {
     const auto& handle_table = Core::CurrentProcess()->GetHandleTable();
     const SharedPtr<Thread> thread = handle_table.Get<Thread>(thread_handle);
     if (!thread) {
+        LOG_ERROR(Kernel_SVC, "Thread handle does not exist, thread_handle=0x{:08X}",
+                  thread_handle);
         return ERR_INVALID_HANDLE;
     }
 
@@ -423,10 +498,13 @@ static ResultCode ArbitrateLock(Handle holding_thread_handle, VAddr mutex_addr,
               holding_thread_handle, mutex_addr, requesting_thread_handle);
 
     if (Memory::IsKernelVirtualAddress(mutex_addr)) {
+        LOG_ERROR(Kernel_SVC, "Mutex Address is a kernel virtual address, mutex_addr={:016X}",
+                  mutex_addr);
         return ERR_INVALID_ADDRESS_STATE;
     }
 
     if (!Common::IsWordAligned(mutex_addr)) {
+        LOG_ERROR(Kernel_SVC, "Mutex Address is not word aligned, mutex_addr={:016X}", mutex_addr);
         return ERR_INVALID_ADDRESS;
     }
 
@@ -440,10 +518,13 @@ static ResultCode ArbitrateUnlock(VAddr mutex_addr) {
     LOG_TRACE(Kernel_SVC, "called mutex_addr=0x{:X}", mutex_addr);
 
     if (Memory::IsKernelVirtualAddress(mutex_addr)) {
+        LOG_ERROR(Kernel_SVC, "Mutex Address is a kernel virtual address, mutex_addr={:016X}",
+                  mutex_addr);
         return ERR_INVALID_ADDRESS_STATE;
     }
 
     if (!Common::IsWordAligned(mutex_addr)) {
+        LOG_ERROR(Kernel_SVC, "Mutex Address is not word aligned, mutex_addr={:016X}", mutex_addr);
         return ERR_INVALID_ADDRESS;
     }
 
@@ -601,86 +682,145 @@ static ResultCode GetInfo(u64* result, u64 info_id, u64 handle, u64 info_sub_id)
         ThreadTickCount = 0xF0000002,
     };
 
-    const auto* current_process = Core::CurrentProcess();
-    const auto& vm_manager = current_process->VMManager();
+    const auto info_id_type = static_cast<GetInfoType>(info_id);
 
-    switch (static_cast<GetInfoType>(info_id)) {
+    switch (info_id_type) {
     case GetInfoType::AllowedCpuIdBitmask:
-        *result = current_process->GetAllowedProcessorMask();
-        break;
     case GetInfoType::AllowedThreadPrioBitmask:
-        *result = current_process->GetAllowedThreadPriorityMask();
-        break;
     case GetInfoType::MapRegionBaseAddr:
-        *result = vm_manager.GetMapRegionBaseAddress();
-        break;
     case GetInfoType::MapRegionSize:
-        *result = vm_manager.GetMapRegionSize();
-        break;
     case GetInfoType::HeapRegionBaseAddr:
-        *result = vm_manager.GetHeapRegionBaseAddress();
-        break;
     case GetInfoType::HeapRegionSize:
-        *result = vm_manager.GetHeapRegionSize();
-        break;
+    case GetInfoType::ASLRRegionBaseAddr:
+    case GetInfoType::ASLRRegionSize:
+    case GetInfoType::NewMapRegionBaseAddr:
+    case GetInfoType::NewMapRegionSize:
     case GetInfoType::TotalMemoryUsage:
-        *result = vm_manager.GetTotalMemoryUsage();
-        break;
     case GetInfoType::TotalHeapUsage:
-        *result = vm_manager.GetTotalHeapUsage();
-        break;
+    case GetInfoType::IsVirtualAddressMemoryEnabled:
+    case GetInfoType::PersonalMmHeapUsage:
+    case GetInfoType::TitleId:
+    case GetInfoType::UserExceptionContextAddr: {
+        if (info_sub_id != 0) {
+            return ERR_INVALID_ENUM_VALUE;
+        }
+
+        const auto& current_process_handle_table = Core::CurrentProcess()->GetHandleTable();
+        const auto process = current_process_handle_table.Get<Process>(static_cast<Handle>(handle));
+        if (!process) {
+            return ERR_INVALID_HANDLE;
+        }
+
+        switch (info_id_type) {
+        case GetInfoType::AllowedCpuIdBitmask:
+            *result = process->GetAllowedProcessorMask();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::AllowedThreadPrioBitmask:
+            *result = process->GetAllowedThreadPriorityMask();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::MapRegionBaseAddr:
+            *result = process->VMManager().GetMapRegionBaseAddress();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::MapRegionSize:
+            *result = process->VMManager().GetMapRegionSize();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::HeapRegionBaseAddr:
+            *result = process->VMManager().GetHeapRegionBaseAddress();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::HeapRegionSize:
+            *result = process->VMManager().GetHeapRegionSize();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::ASLRRegionBaseAddr:
+            *result = process->VMManager().GetASLRRegionBaseAddress();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::ASLRRegionSize:
+            *result = process->VMManager().GetASLRRegionSize();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::NewMapRegionBaseAddr:
+            *result = process->VMManager().GetNewMapRegionBaseAddress();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::NewMapRegionSize:
+            *result = process->VMManager().GetNewMapRegionSize();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::TotalMemoryUsage:
+            *result = process->VMManager().GetTotalMemoryUsage();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::TotalHeapUsage:
+            *result = process->VMManager().GetTotalHeapUsage();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::IsVirtualAddressMemoryEnabled:
+            *result = process->IsVirtualMemoryEnabled();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::TitleId:
+            *result = process->GetTitleID();
+            return RESULT_SUCCESS;
+
+        case GetInfoType::UserExceptionContextAddr:
+            LOG_WARNING(Kernel_SVC,
+                        "(STUBBED) Attempted to query user exception context address, returned 0");
+            *result = 0;
+            return RESULT_SUCCESS;
+
+        default:
+            break;
+        }
+
+        LOG_WARNING(Kernel_SVC, "(STUBBED) Unimplemented svcGetInfo id=0x{:016X}", info_id);
+        return ERR_INVALID_ENUM_VALUE;
+    }
+
     case GetInfoType::IsCurrentProcessBeingDebugged:
         *result = 0;
-        break;
+        return RESULT_SUCCESS;
+
     case GetInfoType::RandomEntropy:
         if (handle != 0) {
+            LOG_ERROR(Kernel_SVC, "Process Handle is non zero, expected 0 result but got {:016X}",
+                      handle);
             return ERR_INVALID_HANDLE;
         }
 
         if (info_sub_id >= Process::RANDOM_ENTROPY_SIZE) {
+            LOG_ERROR(Kernel_SVC, "Entropy size is out of range, expected {} but got {}",
+                      Process::RANDOM_ENTROPY_SIZE, info_sub_id);
             return ERR_INVALID_COMBINATION;
         }
 
-        *result = current_process->GetRandomEntropy(info_sub_id);
+        *result = Core::CurrentProcess()->GetRandomEntropy(info_sub_id);
         return RESULT_SUCCESS;
-        break;
-    case GetInfoType::ASLRRegionBaseAddr:
-        *result = vm_manager.GetASLRRegionBaseAddress();
-        break;
-    case GetInfoType::ASLRRegionSize:
-        *result = vm_manager.GetASLRRegionSize();
-        break;
-    case GetInfoType::NewMapRegionBaseAddr:
-        *result = vm_manager.GetNewMapRegionBaseAddress();
-        break;
-    case GetInfoType::NewMapRegionSize:
-        *result = vm_manager.GetNewMapRegionSize();
-        break;
-    case GetInfoType::IsVirtualAddressMemoryEnabled:
-        *result = current_process->IsVirtualMemoryEnabled();
-        break;
-    case GetInfoType::TitleId:
-        *result = current_process->GetTitleID();
-        break;
+
     case GetInfoType::PrivilegedProcessId:
         LOG_WARNING(Kernel_SVC,
                     "(STUBBED) Attempted to query privileged process id bounds, returned 0");
         *result = 0;
-        break;
-    case GetInfoType::UserExceptionContextAddr:
-        LOG_WARNING(Kernel_SVC,
-                    "(STUBBED) Attempted to query user exception context address, returned 0");
-        *result = 0;
-        break;
+        return RESULT_SUCCESS;
+
     case GetInfoType::ThreadTickCount: {
         constexpr u64 num_cpus = 4;
         if (info_sub_id != 0xFFFFFFFFFFFFFFFF && info_sub_id >= num_cpus) {
+            LOG_ERROR(Kernel_SVC, "Core count is out of range, expected {} but got {}", num_cpus,
+                      info_sub_id);
             return ERR_INVALID_COMBINATION;
         }
 
         const auto thread =
-            current_process->GetHandleTable().Get<Thread>(static_cast<Handle>(handle));
+            Core::CurrentProcess()->GetHandleTable().Get<Thread>(static_cast<Handle>(handle));
         if (!thread) {
+            LOG_ERROR(Kernel_SVC, "Thread handle does not exist, handle=0x{:08X}",
+                      static_cast<Handle>(handle));
             return ERR_INVALID_HANDLE;
         }
 
@@ -700,14 +840,13 @@ static ResultCode GetInfo(u64* result, u64 info_id, u64 handle, u64 info_sub_id)
         }
 
         *result = out_ticks;
-        break;
+        return RESULT_SUCCESS;
     }
+
     default:
         LOG_WARNING(Kernel_SVC, "(STUBBED) Unimplemented svcGetInfo id=0x{:016X}", info_id);
         return ERR_INVALID_ENUM_VALUE;
     }
-
-    return RESULT_SUCCESS;
 }
 
 /// Sets the thread activity
@@ -723,14 +862,22 @@ static ResultCode GetThreadContext(VAddr thread_context, Handle handle) {
     const auto* current_process = Core::CurrentProcess();
     const SharedPtr<Thread> thread = current_process->GetHandleTable().Get<Thread>(handle);
     if (!thread) {
+        LOG_ERROR(Kernel_SVC, "Thread handle does not exist, handle=0x{:08X}", handle);
         return ERR_INVALID_HANDLE;
     }
 
     if (thread->GetOwnerProcess() != current_process) {
+        LOG_ERROR(Kernel_SVC,
+                  "The current process does not own the current thread, thread_handle={:08X} "
+                  "thread_pid={}, "
+                  "current_process_pid={}",
+                  handle, thread->GetOwnerProcess()->GetProcessID(),
+                  current_process->GetProcessID());
         return ERR_INVALID_HANDLE;
     }
 
     if (thread == GetCurrentThread()) {
+        LOG_ERROR(Kernel_SVC, "The thread handle specified is the current running thread");
         return ERR_ALREADY_REGISTERED;
     }
 
@@ -751,9 +898,12 @@ static ResultCode GetThreadContext(VAddr thread_context, Handle handle) {
 
 /// Gets the priority for the specified thread
 static ResultCode GetThreadPriority(u32* priority, Handle handle) {
+    LOG_TRACE(Kernel_SVC, "called");
+
     const auto& handle_table = Core::CurrentProcess()->GetHandleTable();
     const SharedPtr<Thread> thread = handle_table.Get<Thread>(handle);
     if (!thread) {
+        LOG_ERROR(Kernel_SVC, "Thread handle does not exist, handle=0x{:08X}", handle);
         return ERR_INVALID_HANDLE;
     }
 
@@ -763,7 +913,13 @@ static ResultCode GetThreadPriority(u32* priority, Handle handle) {
 
 /// Sets the priority for the specified thread
 static ResultCode SetThreadPriority(Handle handle, u32 priority) {
+    LOG_TRACE(Kernel_SVC, "called");
+
     if (priority > THREADPRIO_LOWEST) {
+        LOG_ERROR(
+            Kernel_SVC,
+            "An invalid priority was specified, expected {} but got {} for thread_handle={:08X}",
+            THREADPRIO_LOWEST, priority, handle);
         return ERR_INVALID_THREAD_PRIORITY;
     }
 
@@ -771,6 +927,7 @@ static ResultCode SetThreadPriority(Handle handle, u32 priority) {
 
     SharedPtr<Thread> thread = current_process->GetHandleTable().Get<Thread>(handle);
     if (!thread) {
+        LOG_ERROR(Kernel_SVC, "Thread handle does not exist, handle=0x{:08X}", handle);
         return ERR_INVALID_HANDLE;
     }
 
@@ -793,32 +950,46 @@ static ResultCode MapSharedMemory(Handle shared_memory_handle, VAddr addr, u64 s
               shared_memory_handle, addr, size, permissions);
 
     if (!Common::Is4KBAligned(addr)) {
+        LOG_ERROR(Kernel_SVC, "Address is not aligned to 4KB, addr=0x{:016X}", addr);
         return ERR_INVALID_ADDRESS;
     }
 
-    if (size == 0 || !Common::Is4KBAligned(size)) {
+    if (size == 0) {
+        LOG_ERROR(Kernel_SVC, "Size is 0");
+        return ERR_INVALID_SIZE;
+    }
+
+    if (!Common::Is4KBAligned(size)) {
+        LOG_ERROR(Kernel_SVC, "Size is not aligned to 4KB, size=0x{:016X}", size);
         return ERR_INVALID_SIZE;
     }
 
     if (!IsValidAddressRange(addr, size)) {
+        LOG_ERROR(Kernel_SVC, "Region is not a valid address range, addr=0x{:016X}, size=0x{:016X}",
+                  addr, size);
         return ERR_INVALID_ADDRESS_STATE;
     }
 
     const auto permissions_type = static_cast<MemoryPermission>(permissions);
     if (permissions_type != MemoryPermission::Read &&
         permissions_type != MemoryPermission::ReadWrite) {
-        LOG_ERROR(Kernel_SVC, "Invalid permissions=0x{:08X}", permissions);
+        LOG_ERROR(Kernel_SVC, "Expected Read or ReadWrite permission but got permissions=0x{:08X}",
+                  permissions);
         return ERR_INVALID_MEMORY_PERMISSIONS;
     }
 
     auto* const current_process = Core::CurrentProcess();
     auto shared_memory = current_process->GetHandleTable().Get<SharedMemory>(shared_memory_handle);
     if (!shared_memory) {
+        LOG_ERROR(Kernel_SVC, "Shared memory does not exist, shared_memory_handle=0x{:08X}",
+                  shared_memory_handle);
         return ERR_INVALID_HANDLE;
     }
 
     const auto& vm_manager = current_process->VMManager();
     if (!vm_manager.IsWithinASLRRegion(addr, size)) {
+        LOG_ERROR(Kernel_SVC, "Region is not within the ASLR region. addr=0x{:016X}, size={:016X}",
+                  addr, size);
         return ERR_INVALID_MEMORY_RANGE;
     }
 
@@ -830,25 +1001,38 @@ static ResultCode UnmapSharedMemory(Handle shared_memory_handle, VAddr addr, u64
                 shared_memory_handle, addr, size);
 
     if (!Common::Is4KBAligned(addr)) {
+        LOG_ERROR(Kernel_SVC, "Address is not aligned to 4KB, addr=0x{:016X}", addr);
         return ERR_INVALID_ADDRESS;
     }
 
-    if (size == 0 || !Common::Is4KBAligned(size)) {
+    if (size == 0) {
+        LOG_ERROR(Kernel_SVC, "Size is 0");
+        return ERR_INVALID_SIZE;
+    }
+
+    if (!Common::Is4KBAligned(size)) {
+        LOG_ERROR(Kernel_SVC, "Size is not aligned to 4KB, size=0x{:016X}", size);
         return ERR_INVALID_SIZE;
     }
 
     if (!IsValidAddressRange(addr, size)) {
+        LOG_ERROR(Kernel_SVC, "Region is not a valid address range, addr=0x{:016X}, size=0x{:016X}",
+                  addr, size);
         return ERR_INVALID_ADDRESS_STATE;
     }
 
     auto* const current_process = Core::CurrentProcess();
     auto shared_memory = current_process->GetHandleTable().Get<SharedMemory>(shared_memory_handle);
     if (!shared_memory) {
+        LOG_ERROR(Kernel_SVC, "Shared memory does not exist, shared_memory_handle=0x{:08X}",
+                  shared_memory_handle);
         return ERR_INVALID_HANDLE;
     }
 
     const auto& vm_manager = current_process->VMManager();
     if (!vm_manager.IsWithinASLRRegion(addr, size)) {
+        LOG_ERROR(Kernel_SVC, "Region is not within the ASLR region. addr=0x{:016X}, size={:016X}",
+                  addr, size);
         return ERR_INVALID_MEMORY_RANGE;
     }
 
@@ -858,9 +1042,12 @@ static ResultCode UnmapSharedMemory(Handle shared_memory_handle, VAddr addr, u64
 /// Query process memory
 static ResultCode QueryProcessMemory(MemoryInfo* memory_info, PageInfo* /*page_info*/,
                                      Handle process_handle, u64 addr) {
+    LOG_TRACE(Kernel_SVC, "called process=0x{:08X} addr={:X}", process_handle, addr);
     const auto& handle_table = Core::CurrentProcess()->GetHandleTable();
     SharedPtr<Process> process = handle_table.Get<Process>(process_handle);
     if (!process) {
+        LOG_ERROR(Kernel_SVC, "Process handle does not exist, process_handle=0x{:08X}",
+                  process_handle);
         return ERR_INVALID_HANDLE;
     }
     auto vma = process->VMManager().FindVMA(addr);
@@ -876,8 +1063,6 @@ static ResultCode QueryProcessMemory(MemoryInfo* memory_info, PageInfo* /*page_i
         memory_info->size = vma->second.size;
         memory_info->type = static_cast<u32>(vma->second.meminfo_state);
     }
-
-    LOG_TRACE(Kernel_SVC, "called process=0x{:08X} addr={:X}", process_handle, addr);
     return RESULT_SUCCESS;
 }
 
@@ -906,7 +1091,14 @@ static void ExitProcess() {
 /// Creates a new thread
 static ResultCode CreateThread(Handle* out_handle, VAddr entry_point, u64 arg, VAddr stack_top,
                                u32 priority, s32 processor_id) {
+    LOG_TRACE(Kernel_SVC,
+              "called entrypoint=0x{:08X} ({}), arg=0x{:08X}, stacktop=0x{:08X}, "
+              "threadpriority=0x{:08X}, processorid=0x{:08X} : created handle=0x{:08X}",
+              entry_point, arg, stack_top, priority, processor_id, *out_handle);
+
     if (priority > THREADPRIO_LOWEST) {
+        LOG_ERROR(Kernel_SVC, "An invalid priority was specified, expected {} but got {}",
+                  THREADPRIO_LOWEST, priority);
         return ERR_INVALID_THREAD_PRIORITY;
     }
 
@@ -937,6 +1129,8 @@ static ResultCode CreateThread(Handle* out_handle, VAddr entry_point, u64 arg, V
 
     const auto new_guest_handle = current_process->GetHandleTable().Create(thread);
     if (new_guest_handle.Failed()) {
+        LOG_ERROR(Kernel_SVC, "Failed to create handle with error=0x{:X}",
+                  new_guest_handle.Code().raw);
         return new_guest_handle.Code();
     }
     thread->SetGuestHandle(*new_guest_handle);
@@ -944,11 +1138,6 @@ static ResultCode CreateThread(Handle* out_handle, VAddr entry_point, u64 arg, V
 
     Core::System::GetInstance().CpuCore(thread->GetProcessorID()).PrepareReschedule();
 
-    LOG_TRACE(Kernel_SVC,
-              "called entrypoint=0x{:08X} ({}), arg=0x{:08X}, stacktop=0x{:08X}, "
-              "threadpriority=0x{:08X}, processorid=0x{:08X} : created handle=0x{:08X}",
-              entry_point, name, arg, stack_top, priority, processor_id, *out_handle);
-
     return RESULT_SUCCESS;
 }
 
@@ -959,6 +1148,8 @@ static ResultCode StartThread(Handle thread_handle) {
     const auto& handle_table = Core::CurrentProcess()->GetHandleTable();
     const SharedPtr<Thread> thread = handle_table.Get<Thread>(thread_handle);
     if (!thread) {
+        LOG_ERROR(Kernel_SVC, "Thread handle does not exist, thread_handle=0x{:08X}",
+                  thread_handle);
         return ERR_INVALID_HANDLE;
     }
 
@@ -1138,10 +1329,12 @@ static ResultCode WaitForAddress(VAddr address, u32 type, s32 value, s64 timeout
                 address, type, value, timeout);
     // If the passed address is a kernel virtual address, return invalid memory state.
     if (Memory::IsKernelVirtualAddress(address)) {
+        LOG_ERROR(Kernel_SVC, "Address is a kernel virtual address, address={:016X}", address);
         return ERR_INVALID_ADDRESS_STATE;
     }
     // If the address is not properly aligned to 4 bytes, return invalid address.
-    if (address % sizeof(u32) != 0) {
+    if (!Common::IsWordAligned(address)) {
+        LOG_ERROR(Kernel_SVC, "Address is not word aligned, address={:016X}", address);
         return ERR_INVALID_ADDRESS;
     }
 
@@ -1153,6 +1346,10 @@ static ResultCode WaitForAddress(VAddr address, u32 type, s32 value, s64 timeout
     case AddressArbiter::ArbitrationType::WaitIfEqual:
         return AddressArbiter::WaitForAddressIfEqual(address, value, timeout);
     default:
+        LOG_ERROR(Kernel_SVC,
+                  "Invalid arbitration type, expected WaitIfLessThan, DecrementAndWaitIfLessThan "
+                  "or WaitIfEqual but got {}",
+                  type);
         return ERR_INVALID_ENUM_VALUE;
     }
 }
@@ -1163,10 +1360,12 @@ static ResultCode SignalToAddress(VAddr address, u32 type, s32 value, s32 num_to
                 address, type, value, num_to_wake);
     // If the passed address is a kernel virtual address, return invalid memory state.
     if (Memory::IsKernelVirtualAddress(address)) {
+        LOG_ERROR(Kernel_SVC, "Address is a kernel virtual address, address={:016X}", address);
         return ERR_INVALID_ADDRESS_STATE;
     }
     // If the address is not properly aligned to 4 bytes, return invalid address.
-    if (address % sizeof(u32) != 0) {
+    if (!Common::IsWordAligned(address)) {
+        LOG_ERROR(Kernel_SVC, "Address is not word aligned, address={:016X}", address);
         return ERR_INVALID_ADDRESS;
     }
 
@@ -1179,12 +1378,18 @@ static ResultCode SignalToAddress(VAddr address, u32 type, s32 value, s32 num_to
         return AddressArbiter::ModifyByWaitingCountAndSignalToAddressIfEqual(address, value,
                                                                              num_to_wake);
     default:
+        LOG_ERROR(Kernel_SVC,
+                  "Invalid signal type, expected Signal, IncrementAndSignalIfEqual "
+                  "or ModifyByWaitingCountAndSignalIfEqual but got {}",
+                  type);
         return ERR_INVALID_ENUM_VALUE;
     }
 }
 
 /// This returns the total CPU ticks elapsed since the CPU was powered-on
 static u64 GetSystemTick() {
+    LOG_TRACE(Kernel_SVC, "called");
+
     const u64 result{CoreTiming::GetTicks()};
 
     // Advance time to defeat dumb games that busy-wait for the frame to end.
@@ -1258,6 +1463,8 @@ static ResultCode GetThreadCoreMask(Handle thread_handle, u32* core, u64* mask)
     const auto& handle_table = Core::CurrentProcess()->GetHandleTable();
     const SharedPtr<Thread> thread = handle_table.Get<Thread>(thread_handle);
     if (!thread) {
+        LOG_ERROR(Kernel_SVC, "Thread handle does not exist, thread_handle=0x{:08X}",
+                  thread_handle);
         return ERR_INVALID_HANDLE;
     }
 
@@ -1268,12 +1475,14 @@ static ResultCode GetThreadCoreMask(Handle thread_handle, u32* core, u64* mask)
 }
 
 static ResultCode SetThreadCoreMask(Handle thread_handle, u32 core, u64 mask) {
-    LOG_DEBUG(Kernel_SVC, "called, handle=0x{:08X}, mask=0x{:16X}, core=0x{:X}", thread_handle,
+    LOG_DEBUG(Kernel_SVC, "called, handle=0x{:08X}, mask=0x{:016X}, core=0x{:X}", thread_handle,
               mask, core);
 
     const auto& handle_table = Core::CurrentProcess()->GetHandleTable();
     const SharedPtr<Thread> thread = handle_table.Get<Thread>(thread_handle);
     if (!thread) {
+        LOG_ERROR(Kernel_SVC, "Thread handle does not exist, thread_handle=0x{:08X}",
+                  thread_handle);
         return ERR_INVALID_HANDLE;
     }
 
@@ -1288,6 +1497,7 @@ static ResultCode SetThreadCoreMask(Handle thread_handle, u32 core, u64 mask) {
     }
 
     if (mask == 0) {
+        LOG_ERROR(Kernel_SVC, "Mask is 0");
         return ERR_INVALID_COMBINATION;
     }
 
@@ -1297,11 +1507,14 @@ static ResultCode SetThreadCoreMask(Handle thread_handle, u32 core, u64 mask) {
     if (core == OnlyChangeMask) {
         core = thread->GetIdealCore();
     } else if (core >= Core::NUM_CPU_CORES && core != static_cast<u32>(-1)) {
+        LOG_ERROR(Kernel_SVC, "Invalid core specified, got {}", core);
         return ERR_INVALID_PROCESSOR_ID;
     }
 
     // Error out if the input core isn't enabled in the input mask.
     if (core < Core::NUM_CPU_CORES && (mask & (1ull << core)) == 0) {
+        LOG_ERROR(Kernel_SVC, "Core is not enabled for the current mask, core={}, mask={:016X}",
+                  core, mask);
         return ERR_INVALID_COMBINATION;
     }
 
@@ -1314,21 +1527,36 @@ static ResultCode CreateSharedMemory(Handle* handle, u64 size, u32 local_permiss
                                      u32 remote_permissions) {
     LOG_TRACE(Kernel_SVC, "called, size=0x{:X}, localPerms=0x{:08X}, remotePerms=0x{:08X}", size,
               local_permissions, remote_permissions);
+    if (size == 0) {
+        LOG_ERROR(Kernel_SVC, "Size is 0");
+        return ERR_INVALID_SIZE;
+    }
+    if (!Common::Is4KBAligned(size)) {
+        LOG_ERROR(Kernel_SVC, "Size is not aligned to 4KB, 0x{:016X}", size);
+        return ERR_INVALID_SIZE;
+    }
 
-    // Size must be a multiple of 4KB and be less than or equal to
-    // approx. 8 GB (actually (1GB - 512B) * 8)
-    if (size == 0 || (size & 0xFFFFFFFE00000FFF) != 0) {
+    if (size >= MAIN_MEMORY_SIZE) {
+        LOG_ERROR(Kernel_SVC, "Size is not less than 8GB, 0x{:016X}", size);
         return ERR_INVALID_SIZE;
     }
 
     const auto local_perms = static_cast<MemoryPermission>(local_permissions);
     if (local_perms != MemoryPermission::Read && local_perms != MemoryPermission::ReadWrite) {
+        LOG_ERROR(Kernel_SVC,
+                  "Invalid local memory permissions, expected Read or ReadWrite but got "
+                  "local_permissions={}",
+                  static_cast<u32>(local_permissions));
         return ERR_INVALID_MEMORY_PERMISSIONS;
     }
 
     const auto remote_perms = static_cast<MemoryPermission>(remote_permissions);
     if (remote_perms != MemoryPermission::Read && remote_perms != MemoryPermission::ReadWrite &&
         remote_perms != MemoryPermission::DontCare) {
+        LOG_ERROR(Kernel_SVC,
+                  "Invalid remote memory permissions, expected Read, ReadWrite or DontCare but got "
+                  "remote_permissions={}",
+                  static_cast<u32>(remote_permissions));
         return ERR_INVALID_MEMORY_PERMISSIONS;
     }
 
@@ -1348,6 +1576,7 @@ static ResultCode ClearEvent(Handle handle) {
     const auto& handle_table = Core::CurrentProcess()->GetHandleTable();
     SharedPtr<Event> evt = handle_table.Get<Event>(handle);
     if (evt == nullptr) {
+        LOG_ERROR(Kernel_SVC, "Event handle does not exist, handle=0x{:08X}", handle);
         return ERR_INVALID_HANDLE;
     }
 
@@ -1366,11 +1595,14 @@ static ResultCode GetProcessInfo(u64* out, Handle process_handle, u32 type) {
     const auto& handle_table = Core::CurrentProcess()->GetHandleTable();
     const auto process = handle_table.Get<Process>(process_handle);
     if (!process) {
+        LOG_ERROR(Kernel_SVC, "Process handle does not exist, process_handle=0x{:08X}",
+                  process_handle);
         return ERR_INVALID_HANDLE;
     }
 
     const auto info_type = static_cast<InfoType>(type);
     if (info_type != InfoType::Status) {
+        LOG_ERROR(Kernel_SVC, "Expected info_type to be Status but got {} instead", type);
         return ERR_INVALID_ENUM_VALUE;
     }
 

src/core/hle/service/acc/acc.cpp

@@ -21,17 +21,6 @@
 
 namespace Service::Account {
 
-// TODO: RE this structure
-struct UserData {
-    INSERT_PADDING_WORDS(1);
-    u32 icon_id;
-    u8 bg_color_id;
-    INSERT_PADDING_BYTES(0x7);
-    INSERT_PADDING_BYTES(0x10);
-    INSERT_PADDING_BYTES(0x60);
-};
-static_assert(sizeof(UserData) == 0x80, "UserData structure has incorrect size");
-
 // Smallest JPEG https://github.com/mathiasbynens/small/blob/master/jpeg.jpg
 // used as a backup should the one on disk not exist
 constexpr u32 backup_jpeg_size = 107;
@@ -72,9 +61,11 @@ private:
     void Get(Kernel::HLERequestContext& ctx) {
         LOG_INFO(Service_ACC, "called user_id={}", user_id.Format());
         ProfileBase profile_base{};
-        std::array<u8, MAX_DATA> data{};
+        ProfileData data{};
         if (profile_manager.GetProfileBaseAndData(user_id, profile_base, data)) {
-            ctx.WriteBuffer(data);
+            std::array<u8, sizeof(ProfileData)> raw_data;
+            std::memcpy(raw_data.data(), &data, sizeof(ProfileData));
+            ctx.WriteBuffer(raw_data);
             IPC::ResponseBuilder rb{ctx, 16};
             rb.Push(RESULT_SUCCESS);
             rb.PushRaw(profile_base);
@@ -216,10 +207,11 @@ void Module::Interface::GetLastOpenedUser(Kernel::HLERequestContext& ctx) {
 void Module::Interface::GetProfile(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
     UUID user_id = rp.PopRaw<UUID>();
+    LOG_DEBUG(Service_ACC, "called user_id={}", user_id.Format());
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<IProfile>(user_id, *profile_manager);
-    LOG_DEBUG(Service_ACC, "called user_id={}", user_id.Format());
 }
 
 void Module::Interface::IsUserRegistrationRequestPermitted(Kernel::HLERequestContext& ctx) {
@@ -236,10 +228,10 @@ void Module::Interface::InitializeApplicationInfo(Kernel::HLERequestContext& ctx
 }
 
 void Module::Interface::GetBaasAccountManagerForApplication(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_ACC, "called");
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<IManagerForApplication>();
-    LOG_DEBUG(Service_ACC, "called");
 }
 
 void Module::Interface::TrySelectUserWithoutInteraction(Kernel::HLERequestContext& ctx) {

src/core/hle/service/acc/profile_manager.cpp

@@ -18,7 +18,7 @@ struct UserRaw {
     UUID uuid2;
     u64 timestamp;
     ProfileUsername username;
-    INSERT_PADDING_BYTES(0x80);
+    ProfileData extra_data;
 };
 static_assert(sizeof(UserRaw) == 0xC8, "UserRaw has incorrect size.");
 
@@ -346,7 +346,7 @@ void ProfileManager::ParseUserSaveFile() {
             continue;
         }
 
-        AddUser({user.uuid, user.username, user.timestamp, {}, false});
+        AddUser({user.uuid, user.username, user.timestamp, user.extra_data, false});
     }
 
     std::stable_partition(profiles.begin(), profiles.end(),
@@ -361,6 +361,7 @@ void ProfileManager::WriteUserSaveFile() {
         raw.users[i].uuid2 = profiles[i].user_uuid;
         raw.users[i].uuid = profiles[i].user_uuid;
         raw.users[i].timestamp = profiles[i].creation_time;
+        raw.users[i].extra_data = profiles[i].data;
     }
 
     const auto raw_path =

src/core/hle/service/acc/profile_manager.h

@@ -13,7 +13,6 @@
 
 namespace Service::Account {
 constexpr std::size_t MAX_USERS = 8;
-constexpr std::size_t MAX_DATA = 128;
 constexpr u128 INVALID_UUID{{0, 0}};
 
 struct UUID {
@@ -50,9 +49,20 @@ static_assert(sizeof(UUID) == 16, "UUID is an invalid size!");
 
 constexpr std::size_t profile_username_size = 32;
 using ProfileUsername = std::array<u8, profile_username_size>;
-using ProfileData = std::array<u8, MAX_DATA>;
 using UserIDArray = std::array<UUID, MAX_USERS>;
 
+/// Contains extra data related to a user.
+/// TODO: RE this structure
+struct ProfileData {
+    INSERT_PADDING_WORDS(1);
+    u32 icon_id;
+    u8 bg_color_id;
+    INSERT_PADDING_BYTES(0x7);
+    INSERT_PADDING_BYTES(0x10);
+    INSERT_PADDING_BYTES(0x60);
+};
+static_assert(sizeof(ProfileData) == 0x80, "ProfileData structure has incorrect size");
+
 /// This holds general information about a users profile. This is where we store all the information
 /// based on a specific user
 struct ProfileInfo {

src/core/hle/service/am/am.cpp

@@ -217,6 +217,7 @@ ISelfController::~ISelfController() = default;
 void ISelfController::SetFocusHandlingMode(Kernel::HLERequestContext& ctx) {
     // Takes 3 input u8s with each field located immediately after the previous
     // u8, these are bool flags. No output.
+    LOG_WARNING(Service_AM, "(STUBBED) called");
 
     IPC::RequestParser rp{ctx};
 
@@ -229,44 +230,40 @@ void ISelfController::SetFocusHandlingMode(Kernel::HLERequestContext& ctx) {
 
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void ISelfController::SetRestartMessageEnabled(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void ISelfController::SetPerformanceModeChangedNotification(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
 
     bool flag = rp.Pop<bool>();
+    LOG_WARNING(Service_AM, "(STUBBED) called flag={}", flag);
 
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called flag={}", flag);
 }
 
 void ISelfController::SetScreenShotPermission(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void ISelfController::SetOperationModeChangedNotification(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
 
     bool flag = rp.Pop<bool>();
+    LOG_WARNING(Service_AM, "(STUBBED) called flag={}", flag);
 
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called flag={}", flag);
 }
 
 void ISelfController::SetOutOfFocusSuspendingEnabled(Kernel::HLERequestContext& ctx) {
@@ -275,45 +272,45 @@ void ISelfController::SetOutOfFocusSuspendingEnabled(Kernel::HLERequestContext&
     IPC::RequestParser rp{ctx};
 
     bool enabled = rp.Pop<bool>();
+    LOG_WARNING(Service_AM, "(STUBBED) called enabled={}", enabled);
 
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called enabled={}", enabled);
 }
 
 void ISelfController::LockExit(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void ISelfController::UnlockExit(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void ISelfController::GetLibraryAppletLaunchableEvent(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     launchable_event->Signal();
 
     IPC::ResponseBuilder rb{ctx, 2, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushCopyObjects(launchable_event);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void ISelfController::SetScreenShotImageOrientation(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void ISelfController::CreateManagedDisplayLayer(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
     // TODO(Subv): Find out how AM determines the display to use, for now just
     // create the layer in the Default display.
     u64 display_id = nvflinger->OpenDisplay("Default");
@@ -322,32 +319,31 @@ void ISelfController::CreateManagedDisplayLayer(Kernel::HLERequestContext& ctx)
     IPC::ResponseBuilder rb{ctx, 4};
     rb.Push(RESULT_SUCCESS);
     rb.Push(layer_id);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void ISelfController::SetHandlesRequestToDisplay(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void ISelfController::SetIdleTimeDetectionExtension(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
     idle_time_detection_extension = rp.Pop<u32>();
+    LOG_WARNING(Service_AM, "(STUBBED) called idle_time_detection_extension={}",
+                idle_time_detection_extension);
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void ISelfController::GetIdleTimeDetectionExtension(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push<u32>(idle_time_detection_extension);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 AppletMessageQueue::AppletMessageQueue() {
@@ -438,47 +434,49 @@ ICommonStateGetter::ICommonStateGetter(std::shared_ptr<AppletMessageQueue> msg_q
 ICommonStateGetter::~ICommonStateGetter() = default;
 
 void ICommonStateGetter::GetBootMode(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
 
     rb.Push<u8>(static_cast<u8>(Service::PM::SystemBootMode::Normal)); // Normal boot mode
-
-    LOG_DEBUG(Service_AM, "called");
 }
 
 void ICommonStateGetter::GetEventHandle(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushCopyObjects(msg_queue->GetMesssageRecieveEvent());
-
-    LOG_DEBUG(Service_AM, "called");
 }
 
 void ICommonStateGetter::ReceiveMessage(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.PushEnum<AppletMessageQueue::AppletMessage>(msg_queue->PopMessage());
-
-    LOG_DEBUG(Service_AM, "called");
 }
 
 void ICommonStateGetter::GetCurrentFocusState(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push(static_cast<u8>(FocusState::InFocus));
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void ICommonStateGetter::GetDefaultDisplayResolutionChangeEvent(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushCopyObjects(msg_queue->GetOperationModeChangedEvent());
-
-    LOG_DEBUG(Service_AM, "called");
 }
 
 void ICommonStateGetter::GetDefaultDisplayResolution(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 4};
     rb.Push(RESULT_SUCCESS);
 
@@ -493,8 +491,6 @@ void ICommonStateGetter::GetDefaultDisplayResolution(Kernel::HLERequestContext&
         rb.Push(static_cast<u32>(Service::VI::DisplayResolution::UndockedHeight) *
                 static_cast<u32>(Settings::values.resolution_factor));
     }
-
-    LOG_DEBUG(Service_AM, "called");
 }
 
 IStorage::IStorage(std::vector<u8> buffer)
@@ -517,21 +513,21 @@ const std::vector<u8>& IStorage::GetData() const {
 
 void ICommonStateGetter::GetOperationMode(Kernel::HLERequestContext& ctx) {
     const bool use_docked_mode{Settings::values.use_docked_mode};
+    LOG_DEBUG(Service_AM, "called, use_docked_mode={}", use_docked_mode);
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push(static_cast<u8>(use_docked_mode ? OperationMode::Docked : OperationMode::Handheld));
-
-    LOG_DEBUG(Service_AM, "called");
 }
 
 void ICommonStateGetter::GetPerformanceMode(Kernel::HLERequestContext& ctx) {
     const bool use_docked_mode{Settings::values.use_docked_mode};
+    LOG_DEBUG(Service_AM, "called, use_docked_mode={}", use_docked_mode);
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push(static_cast<u32>(use_docked_mode ? APM::PerformanceMode::Docked
                                              : APM::PerformanceMode::Handheld));
-
-    LOG_DEBUG(Service_AM, "called");
 }
 
 class ILibraryAppletAccessor final : public ServiceFramework<ILibraryAppletAccessor> {
@@ -566,32 +562,34 @@ public:
 
 private:
     void GetAppletStateChangedEvent(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         const auto event = applet->GetBroker().GetStateChangedEvent();
         event->Signal();
 
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(event);
-
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void IsCompleted(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(applet->TransactionComplete());
-
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetResult(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(applet->GetStatus());
-
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void Start(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         ASSERT(applet != nullptr);
 
         applet->Initialize();
@@ -599,36 +597,39 @@ private:
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void PushInData(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::RequestParser rp{ctx};
         applet->GetBroker().PushNormalDataFromGame(*rp.PopIpcInterface<IStorage>());
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void PopOutData(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
 
         const auto storage = applet->GetBroker().PopNormalDataToGame();
         if (storage == nullptr) {
+            LOG_ERROR(Service_AM,
+                      "storage is a nullptr. There is no data in the current normal channel");
+
             rb.Push(ERR_NO_DATA_IN_CHANNEL);
             return;
         }
 
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IStorage>(std::move(*storage));
-
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void PushInteractiveInData(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::RequestParser rp{ctx};
         applet->GetBroker().PushInteractiveDataFromGame(*rp.PopIpcInterface<IStorage>());
 
@@ -638,51 +639,52 @@ private:
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void PopInteractiveOutData(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
 
         const auto storage = applet->GetBroker().PopInteractiveDataToGame();
         if (storage == nullptr) {
+            LOG_ERROR(Service_AM,
+                      "storage is a nullptr. There is no data in the current interactive channel");
+
             rb.Push(ERR_NO_DATA_IN_CHANNEL);
             return;
         }
 
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IStorage>(std::move(*storage));
-
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetPopOutDataEvent(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(applet->GetBroker().GetNormalDataEvent());
-
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetPopInteractiveOutDataEvent(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(applet->GetBroker().GetInteractiveDataEvent());
-
-        LOG_DEBUG(Service_AM, "called");
     }
 
     std::shared_ptr<Applets::Applet> applet;
 };
 
 void IStorage::Open(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
 
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<IStorageAccessor>(*this);
-
-    LOG_DEBUG(Service_AM, "called");
 }
 
 IStorageAccessor::IStorageAccessor(IStorage& storage)
@@ -701,21 +703,27 @@ IStorageAccessor::IStorageAccessor(IStorage& storage)
 IStorageAccessor::~IStorageAccessor() = default;
 
 void IStorageAccessor::GetSize(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 4};
 
     rb.Push(RESULT_SUCCESS);
     rb.Push(static_cast<u64>(backing.buffer.size()));
-
-    LOG_DEBUG(Service_AM, "called");
 }
 
 void IStorageAccessor::Write(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
 
     const u64 offset{rp.Pop<u64>()};
+    LOG_DEBUG(Service_AM, "called, offset={}", offset);
+
     const std::vector<u8> data{ctx.ReadBuffer()};
 
     if (data.size() > backing.buffer.size() - offset) {
+        LOG_ERROR(Service_AM,
+                  "offset is out of bounds, backing_buffer_sz={}, data_size={}, offset={}",
+                  backing.buffer.size(), data.size(), offset);
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(ERR_SIZE_OUT_OF_BOUNDS);
     }
@@ -724,17 +732,20 @@ void IStorageAccessor::Write(Kernel::HLERequestContext& ctx) {
 
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_DEBUG(Service_AM, "called, offset={}", offset);
 }
 
 void IStorageAccessor::Read(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
 
     const u64 offset{rp.Pop<u64>()};
+    LOG_DEBUG(Service_AM, "called, offset={}", offset);
+
     const std::size_t size{ctx.GetWriteBufferSize()};
 
     if (size > backing.buffer.size() - offset) {
+        LOG_ERROR(Service_AM, "offset is out of bounds, backing_buffer_sz={}, size={}, offset={}",
+                  backing.buffer.size(), size, offset);
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(ERR_SIZE_OUT_OF_BOUNDS);
     }
@@ -743,8 +754,6 @@ void IStorageAccessor::Read(Kernel::HLERequestContext& ctx) {
 
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_DEBUG(Service_AM, "called, offset={}", offset);
 }
 
 ILibraryAppletCreator::ILibraryAppletCreator() : ServiceFramework("ILibraryAppletCreator") {
@@ -783,6 +792,8 @@ void ILibraryAppletCreator::CreateLibraryApplet(Kernel::HLERequestContext& ctx)
     const auto applet = GetAppletFromId(applet_id);
 
     if (applet == nullptr) {
+        LOG_ERROR(Service_AM, "Applet doesn't exist! applet_id={}", static_cast<u32>(applet_id));
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(ResultCode(-1));
         return;
@@ -792,23 +803,23 @@ void ILibraryAppletCreator::CreateLibraryApplet(Kernel::HLERequestContext& ctx)
 
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<AM::ILibraryAppletAccessor>(applet);
-
-    LOG_DEBUG(Service_AM, "called");
 }
 
 void ILibraryAppletCreator::CreateStorage(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
     const u64 size{rp.Pop<u64>()};
+    LOG_DEBUG(Service_AM, "called, size={}", size);
+
     std::vector<u8> buffer(size);
 
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<AM::IStorage>(std::move(buffer));
-
-    LOG_DEBUG(Service_AM, "called, size={}", size);
 }
 
 void ILibraryAppletCreator::CreateTransferMemoryStorage(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::RequestParser rp{ctx};
 
     rp.SetCurrentOffset(3);
@@ -819,6 +830,7 @@ void ILibraryAppletCreator::CreateTransferMemoryStorage(Kernel::HLERequestContex
             handle);
 
     if (shared_mem == nullptr) {
+        LOG_ERROR(Service_AM, "shared_mem is a nullpr for handle={:08X}", handle);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(ResultCode(-1));
         return;
@@ -882,38 +894,45 @@ IApplicationFunctions::IApplicationFunctions() : ServiceFramework("IApplicationF
 IApplicationFunctions::~IApplicationFunctions() = default;
 
 void IApplicationFunctions::EnableApplicationCrashReport(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void IApplicationFunctions::BeginBlockingHomeButtonShortAndLongPressed(
     Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void IApplicationFunctions::EndBlockingHomeButtonShortAndLongPressed(
     Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void IApplicationFunctions::BeginBlockingHomeButton(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void IApplicationFunctions::EndBlockingHomeButton(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void IApplicationFunctions::PopLaunchParameter(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     LaunchParameters params{};
 
     params.magic = POP_LAUNCH_PARAMETER_MAGIC;
@@ -932,21 +951,19 @@ void IApplicationFunctions::PopLaunchParameter(Kernel::HLERequestContext& ctx) {
     std::memcpy(buffer.data(), &params, buffer.size());
 
     rb.PushIpcInterface<AM::IStorage>(buffer);
-
-    LOG_DEBUG(Service_AM, "called");
 }
 
 void IApplicationFunctions::CreateApplicationAndRequestToStartForQuest(
     Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void IApplicationFunctions::EnsureSaveData(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
     u128 uid = rp.PopRaw<u128>(); // What does this do?
-
     LOG_WARNING(Service, "(STUBBED) called uid = {:016X}{:016X}", uid[1], uid[0]);
 
     IPC::ResponseBuilder rb{ctx, 4};
@@ -961,60 +978,62 @@ void IApplicationFunctions::SetTerminateResult(Kernel::HLERequestContext& ctx) {
 
     IPC::RequestParser rp{ctx};
     u32 result = rp.Pop<u32>();
+    LOG_WARNING(Service_AM, "(STUBBED) called, result=0x{:08X}", result);
 
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called, result=0x{:08X}", result);
 }
 
 void IApplicationFunctions::GetDisplayVersion(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 6};
     rb.Push(RESULT_SUCCESS);
     rb.Push<u64>(1);
     rb.Push<u64>(0);
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void IApplicationFunctions::GetDesiredLanguage(Kernel::HLERequestContext& ctx) {
     // TODO(bunnei): This should be configurable
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 4};
     rb.Push(RESULT_SUCCESS);
     rb.Push(
         static_cast<u64>(Service::Set::GetLanguageCodeFromIndex(Settings::values.language_index)));
-    LOG_DEBUG(Service_AM, "called");
 }
 
 void IApplicationFunctions::InitializeGamePlayRecording(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void IApplicationFunctions::SetGamePlayRecordingState(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void IApplicationFunctions::NotifyRunning(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push<u8>(0); // Unknown, seems to be ignored by official processes
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void IApplicationFunctions::GetPseudoDeviceId(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 6};
     rb.Push(RESULT_SUCCESS);
 
     // Returns a 128-bit UUID
     rb.Push<u64>(0);
     rb.Push<u64>(0);
-
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 void InstallInterfaces(SM::ServiceManager& service_manager,
@@ -1051,9 +1070,10 @@ IHomeMenuFunctions::IHomeMenuFunctions() : ServiceFramework("IHomeMenuFunctions"
 IHomeMenuFunctions::~IHomeMenuFunctions() = default;
 
 void IHomeMenuFunctions::RequestToGetForeground(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_AM, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_AM, "(STUBBED) called");
 }
 
 IGlobalStateController::IGlobalStateController() : ServiceFramework("IGlobalStateController") {

src/core/hle/service/am/applet_ae.cpp

@@ -32,66 +32,75 @@ public:
 
 private:
     void GetCommonStateGetter(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ICommonStateGetter>(msg_queue);
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetSelfController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ISelfController>(nvflinger);
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetWindowController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IWindowController>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetAudioController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IAudioController>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetDisplayController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IDisplayController>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetProcessWindingController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IProcessWindingController>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetDebugFunctions(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IDebugFunctions>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetLibraryAppletCreator(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ILibraryAppletCreator>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetApplicationFunctions(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IApplicationFunctions>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     std::shared_ptr<NVFlinger::NVFlinger> nvflinger;
@@ -122,97 +131,110 @@ public:
 
 private:
     void GetCommonStateGetter(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ICommonStateGetter>(msg_queue);
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetSelfController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ISelfController>(nvflinger);
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetWindowController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IWindowController>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetAudioController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IAudioController>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetDisplayController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IDisplayController>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetDebugFunctions(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IDebugFunctions>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetLibraryAppletCreator(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ILibraryAppletCreator>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetHomeMenuFunctions(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IHomeMenuFunctions>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetGlobalStateController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IGlobalStateController>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetApplicationCreator(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IApplicationCreator>();
-        LOG_DEBUG(Service_AM, "called");
     }
     std::shared_ptr<NVFlinger::NVFlinger> nvflinger;
     std::shared_ptr<AppletMessageQueue> msg_queue;
 };
 
 void AppletAE::OpenSystemAppletProxy(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<ISystemAppletProxy>(nvflinger, msg_queue);
-    LOG_DEBUG(Service_AM, "called");
 }
 
 void AppletAE::OpenLibraryAppletProxy(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<ILibraryAppletProxy>(nvflinger, msg_queue);
-    LOG_DEBUG(Service_AM, "called");
 }
 
 void AppletAE::OpenLibraryAppletProxyOld(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<ILibraryAppletProxy>(nvflinger, msg_queue);
-    LOG_DEBUG(Service_AM, "called");
 }
 
 AppletAE::AppletAE(std::shared_ptr<NVFlinger::NVFlinger> nvflinger,

src/core/hle/service/am/applet_oe.cpp

@@ -35,59 +35,67 @@ public:
 
 private:
     void GetAudioController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IAudioController>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetDisplayController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IDisplayController>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetDebugFunctions(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IDebugFunctions>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetWindowController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IWindowController>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetSelfController(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ISelfController>(nvflinger);
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetCommonStateGetter(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ICommonStateGetter>(msg_queue);
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetLibraryAppletCreator(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ILibraryAppletCreator>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     void GetApplicationFunctions(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_AM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IApplicationFunctions>();
-        LOG_DEBUG(Service_AM, "called");
     }
 
     std::shared_ptr<NVFlinger::NVFlinger> nvflinger;
@@ -95,10 +103,11 @@ private:
 };
 
 void AppletOE::OpenApplicationProxy(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AM, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<IApplicationProxy>(nvflinger, msg_queue);
-    LOG_DEBUG(Service_AM, "called");
 }
 
 AppletOE::AppletOE(std::shared_ptr<NVFlinger::NVFlinger> nvflinger,

src/core/hle/service/aoc/aoc_u.cpp

@@ -68,6 +68,8 @@ AOC_U::AOC_U() : ServiceFramework("aoc:u"), add_on_content(AccumulateAOCTitleIDs
 AOC_U::~AOC_U() = default;
 
 void AOC_U::CountAddOnContent(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AOC, "called");
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
 
@@ -82,6 +84,7 @@ void AOC_U::ListAddOnContent(Kernel::HLERequestContext& ctx) {
 
     const auto offset = rp.PopRaw<u32>();
     auto count = rp.PopRaw<u32>();
+    LOG_DEBUG(Service_AOC, "called with offset={}, count={}", offset, count);
 
     const auto current = Core::System::GetInstance().CurrentProcess()->GetTitleID();
 
@@ -110,6 +113,8 @@ void AOC_U::ListAddOnContent(Kernel::HLERequestContext& ctx) {
 }
 
 void AOC_U::GetAddOnContentBaseId(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_AOC, "called");
+
     IPC::ResponseBuilder rb{ctx, 4};
     rb.Push(RESULT_SUCCESS);
     const auto title_id = Core::System::GetInstance().CurrentProcess()->GetTitleID();
@@ -128,7 +133,6 @@ void AOC_U::PrepareAddOnContent(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
 
     const auto aoc_id = rp.PopRaw<u32>();
-
     LOG_WARNING(Service_AOC, "(STUBBED) called with aoc_id={:08X}", aoc_id);
 
     IPC::ResponseBuilder rb{ctx, 2};

src/core/hle/service/apm/interface.cpp

@@ -40,24 +40,22 @@ private:
 
         auto mode = static_cast<PerformanceMode>(rp.Pop<u32>());
         u32 config = rp.Pop<u32>();
+        LOG_WARNING(Service_APM, "(STUBBED) called mode={} config={}", static_cast<u32>(mode),
+                    config);
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-
-        LOG_WARNING(Service_APM, "(STUBBED) called mode={} config={}", static_cast<u32>(mode),
-                    config);
     }
 
     void GetPerformanceConfiguration(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
 
         auto mode = static_cast<PerformanceMode>(rp.Pop<u32>());
+        LOG_WARNING(Service_APM, "(STUBBED) called mode={}", static_cast<u32>(mode));
 
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(static_cast<u32>(PerformanceConfiguration::Config1));
-
-        LOG_WARNING(Service_APM, "(STUBBED) called mode={}", static_cast<u32>(mode));
     }
 };
 
@@ -73,11 +71,11 @@ APM::APM(std::shared_ptr<Module> apm, const char* name)
 APM::~APM() = default;
 
 void APM::OpenSession(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_APM, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<ISession>();
-
-    LOG_DEBUG(Service_APM, "called");
 }
 
 APM_Sys::APM_Sys() : ServiceFramework{"apm:sys"} {
@@ -98,11 +96,11 @@ APM_Sys::APM_Sys() : ServiceFramework{"apm:sys"} {
 APM_Sys::~APM_Sys() = default;
 
 void APM_Sys::GetPerformanceEvent(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_APM, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<ISession>();
-
-    LOG_DEBUG(Service_APM, "called");
 }
 
 } // namespace Service::APM

src/core/hle/service/arp/arp.cpp

@@ -59,11 +59,11 @@ public:
 
 private:
     void AcquireRegistrar(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_ARP, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IRegistrar>();
-
-        LOG_DEBUG(Service_ARP, "called");
     }
 };
 

src/core/hle/service/audio/audout_u.cpp

@@ -86,6 +86,7 @@ private:
 
     void GetAudioOutState(Kernel::HLERequestContext& ctx) {
         LOG_DEBUG(Service_Audio, "called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push(static_cast<u32>(stream->IsPlaying() ? AudioState::Started : AudioState::Stopped));
@@ -148,6 +149,7 @@ private:
 
     void GetReleasedAudioOutBufferImpl(Kernel::HLERequestContext& ctx) {
         LOG_DEBUG(Service_Audio, "called {}", ctx.Description());
+
         IPC::RequestParser rp{ctx};
         const u64 max_count{ctx.GetWriteBufferSize() / sizeof(u64)};
         const auto released_buffers{audio_core.GetTagsAndReleaseBuffers(stream, max_count)};
@@ -163,6 +165,7 @@ private:
 
     void ContainsAudioOutBuffer(Kernel::HLERequestContext& ctx) {
         LOG_DEBUG(Service_Audio, "called");
+
         IPC::RequestParser rp{ctx};
         const u64 tag{rp.Pop<u64>()};
         IPC::ResponseBuilder rb{ctx, 3};
@@ -172,6 +175,7 @@ private:
 
     void GetAudioOutBufferCount(Kernel::HLERequestContext& ctx) {
         LOG_DEBUG(Service_Audio, "called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push(static_cast<u32>(stream->GetQueueSize()));
@@ -189,6 +193,7 @@ private:
 
 void AudOutU::ListAudioOutsImpl(Kernel::HLERequestContext& ctx) {
     LOG_DEBUG(Service_Audio, "called");
+
     IPC::RequestParser rp{ctx};
 
     ctx.WriteBuffer(DefaultDevice);

src/core/hle/service/audio/audren_u.cpp

@@ -52,74 +52,79 @@ private:
     }
 
     void GetSampleRate(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_Audio, "called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(renderer->GetSampleRate());
-        LOG_DEBUG(Service_Audio, "called");
     }
 
     void GetSampleCount(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_Audio, "called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(renderer->GetSampleCount());
-        LOG_DEBUG(Service_Audio, "called");
     }
 
     void GetState(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_Audio, "called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(static_cast<u32>(renderer->GetStreamState()));
-        LOG_DEBUG(Service_Audio, "called");
     }
 
     void GetMixBufferCount(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_Audio, "called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(renderer->GetMixBufferCount());
-        LOG_DEBUG(Service_Audio, "called");
     }
 
     void RequestUpdateImpl(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_Audio, "(STUBBED) called");
+
         ctx.WriteBuffer(renderer->UpdateAudioRenderer(ctx.ReadBuffer()));
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_Audio, "(STUBBED) called");
     }
 
     void Start(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_Audio, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
 
         rb.Push(RESULT_SUCCESS);
-
-        LOG_WARNING(Service_Audio, "(STUBBED) called");
     }
 
     void Stop(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_Audio, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
 
         rb.Push(RESULT_SUCCESS);
-
-        LOG_WARNING(Service_Audio, "(STUBBED) called");
     }
 
     void QuerySystemEvent(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_Audio, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(system_event);
-
-        LOG_WARNING(Service_Audio, "(STUBBED) called");
     }
 
     void SetRenderingTimeLimit(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         rendering_time_limit_percent = rp.Pop<u32>();
+        LOG_DEBUG(Service_Audio, "called. rendering_time_limit_percent={}",
+                  rendering_time_limit_percent);
+
         ASSERT(rendering_time_limit_percent >= 0 && rendering_time_limit_percent <= 100);
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-
-        LOG_DEBUG(Service_Audio, "called. rendering_time_limit_percent={}",
-                  rendering_time_limit_percent);
     }
 
     void GetRenderingTimeLimit(Kernel::HLERequestContext& ctx) {
@@ -211,6 +216,7 @@ private:
 
     void GetActiveChannelCount(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_Audio, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(1);
@@ -235,19 +241,20 @@ AudRenU::AudRenU() : ServiceFramework("audren:u") {
 AudRenU::~AudRenU() = default;
 
 void AudRenU::OpenAudioRenderer(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_Audio, "called");
+
     IPC::RequestParser rp{ctx};
     auto params = rp.PopRaw<AudioCore::AudioRendererParameter>();
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
 
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<Audio::IAudioRenderer>(std::move(params));
-
-    LOG_DEBUG(Service_Audio, "called");
 }
 
 void AudRenU::GetAudioRendererWorkBufferSize(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
     auto params = rp.PopRaw<AudioCore::AudioRendererParameter>();
+    LOG_DEBUG(Service_Audio, "called");
 
     u64 buffer_sz = Common::AlignUp(4 * params.mix_buffer_count, 0x40);
     buffer_sz += params.unknown_c * 1024;
@@ -301,26 +308,26 @@ void AudRenU::GetAudioRendererWorkBufferSize(Kernel::HLERequestContext& ctx) {
     rb.Push(RESULT_SUCCESS);
     rb.Push<u64>(output_sz);
 
-    LOG_DEBUG(Service_Audio, "called, buffer_size=0x{:X}", output_sz);
+    LOG_DEBUG(Service_Audio, "buffer_size=0x{:X}", output_sz);
 }
 
 void AudRenU::GetAudioDevice(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_Audio, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
 
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<Audio::IAudioDevice>();
-
-    LOG_DEBUG(Service_Audio, "called");
 }
 
 void AudRenU::GetAudioDeviceServiceWithRevisionInfo(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_Audio, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
 
     rb.Push(RESULT_SUCCESS);
-    rb.PushIpcInterface<Audio::IAudioDevice>();
-
-    LOG_WARNING(Service_Audio, "(STUBBED) called"); // TODO(ogniK): Figure out what is different
-                                                    // based on the current revision
+    rb.PushIpcInterface<Audio::IAudioDevice>(); // TODO(ogniK): Figure out what is different
+                                                // based on the current revision
 }
 
 bool AudRenU::IsFeatureSupported(AudioFeatures feature, u32_le revision) const {

src/core/hle/service/audio/hwopus.cpp

@@ -46,10 +46,13 @@ public:
 
 private:
     void DecodeInterleaved(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Audio, "called");
+
         u32 consumed = 0;
         u32 sample_count = 0;
         std::vector<opus_int16> samples(ctx.GetWriteBufferSize() / sizeof(opus_int16));
         if (!Decoder_DecodeInterleaved(consumed, sample_count, ctx.ReadBuffer(), samples)) {
+            LOG_ERROR(Audio, "Failed to decode opus data");
             IPC::ResponseBuilder rb{ctx, 2};
             // TODO(ogniK): Use correct error code
             rb.Push(ResultCode(-1));
@@ -63,12 +66,15 @@ private:
     }
 
     void DecodeInterleavedWithPerformance(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Audio, "called");
+
         u32 consumed = 0;
         u32 sample_count = 0;
         u64 performance = 0;
         std::vector<opus_int16> samples(ctx.GetWriteBufferSize() / sizeof(opus_int16));
         if (!Decoder_DecodeInterleaved(consumed, sample_count, ctx.ReadBuffer(), samples,
                                        performance)) {
+            LOG_ERROR(Audio, "Failed to decode opus data");
             IPC::ResponseBuilder rb{ctx, 2};
             // TODO(ogniK): Use correct error code
             rb.Push(ResultCode(-1));
@@ -88,24 +94,39 @@ private:
         std::optional<std::reference_wrapper<u64>> performance_time = std::nullopt) {
         const auto start_time = std::chrono::high_resolution_clock::now();
         std::size_t raw_output_sz = output.size() * sizeof(opus_int16);
-        if (sizeof(OpusHeader) > input.size())
+        if (sizeof(OpusHeader) > input.size()) {
+            LOG_ERROR(Audio, "Input is smaller than the header size, header_sz={}, input_sz={}",
+                      sizeof(OpusHeader), input.size());
             return false;
+        }
         OpusHeader hdr{};
         std::memcpy(&hdr, input.data(), sizeof(OpusHeader));
         if (sizeof(OpusHeader) + static_cast<u32>(hdr.sz) > input.size()) {
+            LOG_ERROR(Audio, "Input does not fit in the opus header size. data_sz={}, input_sz={}",
+                      sizeof(OpusHeader) + static_cast<u32>(hdr.sz), input.size());
             return false;
         }
         auto frame = input.data() + sizeof(OpusHeader);
         auto decoded_sample_count = opus_packet_get_nb_samples(
             frame, static_cast<opus_int32>(input.size() - sizeof(OpusHeader)),
             static_cast<opus_int32>(sample_rate));
-        if (decoded_sample_count * channel_count * sizeof(u16) > raw_output_sz)
+        if (decoded_sample_count * channel_count * sizeof(u16) > raw_output_sz) {
+            LOG_ERROR(
+                Audio,
+                "Decoded data does not fit into the output data, decoded_sz={}, raw_output_sz={}",
+                decoded_sample_count * channel_count * sizeof(u16), raw_output_sz);
             return false;
+        }
+        const int frame_size = (static_cast<int>(raw_output_sz / sizeof(s16) / channel_count));
         auto out_sample_count =
-            opus_decode(decoder.get(), frame, hdr.sz, output.data(),
-                        (static_cast<int>(raw_output_sz / sizeof(s16) / channel_count)), 0);
-        if (out_sample_count < 0)
+            opus_decode(decoder.get(), frame, hdr.sz, output.data(), frame_size, 0);
+        if (out_sample_count < 0) {
+            LOG_ERROR(Audio,
+                      "Incorrect sample count received from opus_decode, "
+                      "output_sample_count={}, frame_size={}, data_sz_from_hdr={}",
+                      out_sample_count, frame_size, static_cast<u32>(hdr.sz));
             return false;
+        }
         const auto end_time = std::chrono::high_resolution_clock::now() - start_time;
         sample_count = out_sample_count;
         consumed = static_cast<u32>(sizeof(OpusHeader) + hdr.sz);
@@ -134,14 +155,17 @@ static std::size_t WorkerBufferSize(u32 channel_count) {
 
 void HwOpus::GetWorkBufferSize(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
-    auto sample_rate = rp.Pop<u32>();
-    auto channel_count = rp.Pop<u32>();
+    const auto sample_rate = rp.Pop<u32>();
+    const auto channel_count = rp.Pop<u32>();
+    LOG_DEBUG(Audio, "called with sample_rate={}, channel_count={}", sample_rate, channel_count);
+
     ASSERT_MSG(sample_rate == 48000 || sample_rate == 24000 || sample_rate == 16000 ||
                    sample_rate == 12000 || sample_rate == 8000,
                "Invalid sample rate");
     ASSERT_MSG(channel_count == 1 || channel_count == 2, "Invalid channel count");
-    u32 worker_buffer_sz = static_cast<u32>(WorkerBufferSize(channel_count));
-    LOG_DEBUG(Audio, "called worker_buffer_sz={}", worker_buffer_sz);
+
+    const u32 worker_buffer_sz = static_cast<u32>(WorkerBufferSize(channel_count));
+    LOG_DEBUG(Audio, "worker_buffer_sz={}", worker_buffer_sz);
 
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
@@ -155,6 +179,7 @@ void HwOpus::OpenOpusDecoder(Kernel::HLERequestContext& ctx) {
     auto buffer_sz = rp.Pop<u32>();
     LOG_DEBUG(Audio, "called sample_rate={}, channel_count={}, buffer_size={}", sample_rate,
               channel_count, buffer_sz);
+
     ASSERT_MSG(sample_rate == 48000 || sample_rate == 24000 || sample_rate == 16000 ||
                    sample_rate == 12000 || sample_rate == 8000,
                "Invalid sample rate");
@@ -164,7 +189,8 @@ void HwOpus::OpenOpusDecoder(Kernel::HLERequestContext& ctx) {
     ASSERT_MSG(buffer_sz >= worker_sz, "Worker buffer too large");
     std::unique_ptr<OpusDecoder, OpusDeleter> decoder{
         static_cast<OpusDecoder*>(operator new(worker_sz))};
-    if (opus_decoder_init(decoder.get(), sample_rate, channel_count)) {
+    if (const int err = opus_decoder_init(decoder.get(), sample_rate, channel_count)) {
+        LOG_ERROR(Audio, "Failed to init opus decoder with error={}", err);
         IPC::ResponseBuilder rb{ctx, 2};
         // TODO(ogniK): Use correct error code
         rb.Push(ResultCode(-1));

src/core/hle/service/bcat/module.cpp

@@ -33,10 +33,11 @@ public:
 };
 
 void Module::Interface::CreateBcatService(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_BCAT, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<IBcatService>();
-    LOG_DEBUG(Service_BCAT, "called");
 }
 
 Module::Interface::Interface(std::shared_ptr<Module> module, const char* name)

src/core/hle/service/btdrv/btdrv.cpp

@@ -34,13 +34,14 @@ public:
 
 private:
     void RegisterEvent(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_BTM, "(STUBBED) called");
+
         auto& kernel = Core::System::GetInstance().Kernel();
         register_event =
             Kernel::Event::Create(kernel, Kernel::ResetType::OneShot, "BT:RegisterEvent");
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(register_event);
-        LOG_WARNING(Service_BTM, "(STUBBED) called");
     }
     Kernel::SharedPtr<Kernel::Event> register_event;
 };

src/core/hle/service/btm/btm.cpp

@@ -57,40 +57,44 @@ public:
 
 private:
     void GetScanEvent(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_BTM, "(STUBBED) called");
+
         auto& kernel = Core::System::GetInstance().Kernel();
         scan_event =
             Kernel::Event::Create(kernel, Kernel::ResetType::OneShot, "IBtmUserCore:ScanEvent");
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(scan_event);
-        LOG_WARNING(Service_BTM, "(STUBBED) called");
     }
     void GetConnectionEvent(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_BTM, "(STUBBED) called");
+
         auto& kernel = Core::System::GetInstance().Kernel();
         connection_event = Kernel::Event::Create(kernel, Kernel::ResetType::OneShot,
                                                  "IBtmUserCore:ConnectionEvent");
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(connection_event);
-        LOG_WARNING(Service_BTM, "(STUBBED) called");
     }
     void GetDiscoveryEvent(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_BTM, "(STUBBED) called");
+
         auto& kernel = Core::System::GetInstance().Kernel();
         service_discovery =
             Kernel::Event::Create(kernel, Kernel::ResetType::OneShot, "IBtmUserCore:Discovery");
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(service_discovery);
-        LOG_WARNING(Service_BTM, "(STUBBED) called");
     }
     void GetConfigEvent(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_BTM, "(STUBBED) called");
+
         auto& kernel = Core::System::GetInstance().Kernel();
         config_event =
             Kernel::Event::Create(kernel, Kernel::ResetType::OneShot, "IBtmUserCore:ConfigEvent");
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(config_event);
-        LOG_WARNING(Service_BTM, "(STUBBED) called");
     }
     Kernel::SharedPtr<Kernel::Event> scan_event;
     Kernel::SharedPtr<Kernel::Event> connection_event;
@@ -111,10 +115,11 @@ public:
 
 private:
     void GetCoreImpl(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_BTM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IBtmUserCore>();
-        LOG_DEBUG(Service_BTM, "called");
     }
 };
 
@@ -209,11 +214,11 @@ public:
 
 private:
     void GetCoreImpl(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_BTM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IBtmSystemCore>();
-
-        LOG_DEBUG(Service_BTM, "called");
     }
 };
 

src/core/hle/service/fgm/fgm.cpp

@@ -42,11 +42,11 @@ public:
 
 private:
     void Initialize(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_FGM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IRequest>();
-
-        LOG_DEBUG(Service_FGM, "called");
     }
 };
 

src/core/hle/service/filesystem/fsp_srv.cpp

@@ -62,11 +62,13 @@ private:
 
         // Error checking
         if (length < 0) {
+            LOG_ERROR(Service_FS, "Length is less than 0, length={}", length);
             IPC::ResponseBuilder rb{ctx, 2};
             rb.Push(FileSys::ERROR_INVALID_SIZE);
             return;
         }
         if (offset < 0) {
+            LOG_ERROR(Service_FS, "Offset is less than 0, offset={}", offset);
             IPC::ResponseBuilder rb{ctx, 2};
             rb.Push(FileSys::ERROR_INVALID_OFFSET);
             return;
@@ -107,11 +109,13 @@ private:
 
         // Error checking
         if (length < 0) {
+            LOG_ERROR(Service_FS, "Length is less than 0, length={}", length);
             IPC::ResponseBuilder rb{ctx, 2};
             rb.Push(FileSys::ERROR_INVALID_SIZE);
             return;
         }
         if (offset < 0) {
+            LOG_ERROR(Service_FS, "Offset is less than 0, offset={}", offset);
             IPC::ResponseBuilder rb{ctx, 2};
             rb.Push(FileSys::ERROR_INVALID_OFFSET);
             return;
@@ -138,11 +142,13 @@ private:
 
         // Error checking
         if (length < 0) {
+            LOG_ERROR(Service_FS, "Length is less than 0, length={}", length);
             IPC::ResponseBuilder rb{ctx, 2};
             rb.Push(FileSys::ERROR_INVALID_SIZE);
             return;
         }
         if (offset < 0) {
+            LOG_ERROR(Service_FS, "Offset is less than 0, offset={}", offset);
             IPC::ResponseBuilder rb{ctx, 2};
             rb.Push(FileSys::ERROR_INVALID_OFFSET);
             return;
@@ -180,9 +186,10 @@ private:
     void SetSize(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         const u64 size = rp.Pop<u64>();
-        backend->Resize(size);
         LOG_DEBUG(Service_FS, "called, size={}", size);
 
+        backend->Resize(size);
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
@@ -465,6 +472,8 @@ public:
     }
 
     void ReadSaveDataInfo(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_FS, "called");
+
         // Calculate how many entries we can fit in the output buffer
         const u64 count_entries = ctx.GetWriteBufferSize() / sizeof(SaveDataInfo);
 
@@ -703,6 +712,8 @@ void FSP_SRV::OpenFileSystemWithPatch(Kernel::HLERequestContext& ctx) {
 
     const auto type = rp.PopRaw<FileSystemType>();
     const auto title_id = rp.PopRaw<u64>();
+    LOG_WARNING(Service_FS, "(STUBBED) called with type={}, title_id={:016X}",
+                static_cast<u8>(type), title_id);
 
     IPC::ResponseBuilder rb{ctx, 2, 0, 0};
     rb.Push(ResultCode(-1));
@@ -738,6 +749,7 @@ void FSP_SRV::MountSaveData(Kernel::HLERequestContext& ctx) {
     auto space_id = rp.PopRaw<FileSys::SaveDataSpaceId>();
     auto unk = rp.Pop<u32>();
     LOG_INFO(Service_FS, "called with unknown={:08X}", unk);
+
     auto save_struct = rp.PopRaw<FileSys::SaveDataDescriptor>();
 
     auto dir = OpenSaveData(space_id, save_struct);
@@ -763,6 +775,7 @@ void FSP_SRV::OpenReadOnlySaveDataFileSystem(Kernel::HLERequestContext& ctx) {
 void FSP_SRV::OpenSaveDataInfoReaderBySaveDataSpaceId(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
     const auto space = rp.PopRaw<FileSys::SaveDataSpaceId>();
+    LOG_INFO(Service_FS, "called, space={}", static_cast<u8>(space));
 
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);

src/core/hle/service/hid/controllers/npad.cpp

@@ -524,6 +524,8 @@ void Controller_NPad::SetNpadMode(u32 npad_id, NPadAssignments assignment_mode)
 
 void Controller_NPad::VibrateController(const std::vector<u32>& controller_ids,
                                         const std::vector<Vibration>& vibrations) {
+    LOG_WARNING(Service_HID, "(STUBBED) called");
+
     if (!can_controllers_vibrate) {
         return;
     }
@@ -533,7 +535,6 @@ void Controller_NPad::VibrateController(const std::vector<u32>& controller_ids,
             // TODO(ogniK): Vibrate the physical controller
         }
     }
-    LOG_WARNING(Service_HID, "(STUBBED) called");
     last_processed_vibration = vibrations.back();
 }
 
@@ -575,8 +576,8 @@ void Controller_NPad::AddNewControllerAt(NPadControllerType controller, u32 npad
         return;
     }
 
-    connected_controllers[npad_id] = {controller, true};
-    InitNewlyAddedControler(npad_id);
+    connected_controllers[NPadIdToIndex(npad_id)] = {controller, true};
+    InitNewlyAddedControler(NPadIdToIndex(npad_id));
 }
 
 void Controller_NPad::ConnectNPad(u32 npad_id) {

src/core/hle/service/hid/controllers/npad.h

@@ -80,9 +80,9 @@ public:
     struct LedPattern {
         explicit LedPattern(u64 light1, u64 light2, u64 light3, u64 light4) {
             position1.Assign(light1);
-            position1.Assign(light2);
-            position1.Assign(light3);
-            position1.Assign(light4);
+            position2.Assign(light2);
+            position3.Assign(light3);
+            position4.Assign(light4);
         }
         union {
             u64 raw{};

src/core/hle/service/hid/hid.cpp

@@ -124,10 +124,11 @@ public:
 
 private:
     void GetSharedMemoryHandle(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(shared_mem);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void UpdateControllers(u64 userdata, int cycles_late) {
@@ -163,9 +164,10 @@ public:
 
 private:
     void ActivateVibrationDevice(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_HID, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 };
 
@@ -303,6 +305,8 @@ private:
     std::shared_ptr<IAppletResource> applet_resource;
 
     void CreateAppletResource(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         if (applet_resource == nullptr) {
             applet_resource = std::make_shared<IAppletResource>();
         }
@@ -310,206 +314,228 @@ private:
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IAppletResource>(applet_resource);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void ActivateXpad(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         applet_resource->ActivateController(HidController::XPad);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void ActivateDebugPad(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         applet_resource->ActivateController(HidController::DebugPad);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void ActivateTouchScreen(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         applet_resource->ActivateController(HidController::Touchscreen);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void ActivateMouse(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         applet_resource->ActivateController(HidController::Mouse);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void ActivateKeyboard(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         applet_resource->ActivateController(HidController::Keyboard);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void ActivateGesture(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         applet_resource->ActivateController(HidController::Gesture);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void ActivateNpadWithRevision(Kernel::HLERequestContext& ctx) {
         // Should have no effect with how our npad sets up the data
+        LOG_DEBUG(Service_HID, "called");
+
         applet_resource->ActivateController(HidController::NPad);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void StartSixAxisSensor(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         auto handle = rp.PopRaw<u32>();
+        LOG_WARNING(Service_HID, "(STUBBED) called with handle={}", handle);
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 
     void SetGyroscopeZeroDriftMode(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_HID, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 
     void IsSixAxisSensorAtRest(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_HID, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         // TODO (Hexagon12): Properly implement reading gyroscope values from controllers.
         rb.Push(true);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 
     void SetSupportedNpadStyleSet(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         auto supported_styleset = rp.PopRaw<u32>();
+        LOG_DEBUG(Service_HID, "called with supported_styleset={}", supported_styleset);
+
         applet_resource->GetController<Controller_NPad>(HidController::NPad)
             .SetSupportedStyleSet({supported_styleset});
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void GetSupportedNpadStyleSet(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         auto& controller = applet_resource->GetController<Controller_NPad>(HidController::NPad);
 
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(controller.GetSupportedStyleSet().raw);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void SetSupportedNpadIdType(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         applet_resource->GetController<Controller_NPad>(HidController::NPad)
             .SetSupportedNPadIdTypes(ctx.ReadBuffer().data(), ctx.GetReadBufferSize());
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void ActivateNpad(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
         applet_resource->ActivateController(HidController::NPad);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void AcquireNpadStyleSetUpdateEventHandle(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         auto npad_id = rp.PopRaw<u32>();
+        LOG_DEBUG(Service_HID, "called with npad_id={}", npad_id);
+
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(applet_resource->GetController<Controller_NPad>(HidController::NPad)
                                .GetStyleSetChangedEvent());
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void DisconnectNpad(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         auto npad_id = rp.PopRaw<u32>();
+        LOG_DEBUG(Service_HID, "called with npad_id={}", npad_id);
+
         applet_resource->GetController<Controller_NPad>(HidController::NPad)
             .DisconnectNPad(npad_id);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void GetPlayerLedPattern(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         auto npad_id = rp.PopRaw<u32>();
+        LOG_DEBUG(Service_HID, "called with npad_id={}", npad_id);
+
         IPC::ResponseBuilder rb{ctx, 4};
         rb.Push(RESULT_SUCCESS);
         rb.PushRaw<u64>(applet_resource->GetController<Controller_NPad>(HidController::NPad)
                             .GetLedPattern(npad_id)
                             .raw);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void SetNpadJoyHoldType(Kernel::HLERequestContext& ctx) {
-        auto& controller = applet_resource->GetController<Controller_NPad>(HidController::NPad);
         IPC::RequestParser rp{ctx};
         const auto hold_type = rp.PopRaw<u64>();
+        LOG_DEBUG(Service_HID, "called with hold_type={}", hold_type);
+
+        auto& controller = applet_resource->GetController<Controller_NPad>(HidController::NPad);
         controller.SetHoldType(Controller_NPad::NpadHoldType{hold_type});
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void GetNpadJoyHoldType(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         const auto& controller =
             applet_resource->GetController<Controller_NPad>(HidController::NPad);
         IPC::ResponseBuilder rb{ctx, 4};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u64>(static_cast<u64>(controller.GetHoldType()));
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void SetNpadJoyAssignmentModeSingleByDefault(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         auto npad_id = rp.PopRaw<u32>();
+        LOG_WARNING(Service_HID, "(STUBBED) called with npad_id={}", npad_id);
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 
     void BeginPermitVibrationSession(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         applet_resource->GetController<Controller_NPad>(HidController::NPad)
             .SetVibrationEnabled(true);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void EndPermitVibrationSession(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         applet_resource->GetController<Controller_NPad>(HidController::NPad)
             .SetVibrationEnabled(false);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void SendVibrationValue(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         const auto controller_id = rp.PopRaw<u32>();
         const auto vibration_values = rp.PopRaw<Controller_NPad::Vibration>();
+        LOG_DEBUG(Service_HID, "called with controller_id={}", controller_id);
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
 
         applet_resource->GetController<Controller_NPad>(HidController::NPad)
             .VibrateController({controller_id}, {vibration_values});
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void SendVibrationValues(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         const auto controllers = ctx.ReadBuffer(0);
         const auto vibrations = ctx.ReadBuffer(1);
 
@@ -527,86 +553,96 @@ private:
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void GetActualVibrationValue(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         IPC::ResponseBuilder rb{ctx, 6};
         rb.Push(RESULT_SUCCESS);
         rb.PushRaw<Controller_NPad::Vibration>(
             applet_resource->GetController<Controller_NPad>(HidController::NPad)
                 .GetLastVibration());
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void SetNpadJoyAssignmentModeDual(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         const auto npad_id = rp.PopRaw<u32>();
+        LOG_DEBUG(Service_HID, "called with npad_id={}", npad_id);
+
         auto& controller = applet_resource->GetController<Controller_NPad>(HidController::NPad);
         controller.SetNpadMode(npad_id, Controller_NPad::NPadAssignments::Dual);
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void MergeSingleJoyAsDualJoy(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_HID, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 
     void SetNpadHandheldActivationMode(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         auto mode = rp.PopRaw<u32>();
+        LOG_WARNING(Service_HID, "(STUBBED) called with mode={}", mode);
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 
     void GetVibrationDeviceInfo(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         IPC::ResponseBuilder rb{ctx, 4};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(1);
         rb.Push<u32>(0);
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void CreateActiveVibrationDeviceList(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_HID, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IActiveVibrationDeviceList>();
-        LOG_DEBUG(Service_HID, "called");
     }
 
     void ActivateConsoleSixAxisSensor(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_HID, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 
     void StartConsoleSixAxisSensor(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_HID, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 
     void StopSixAxisSensor(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_HID, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 
     void SetIsPalmaAllConnectable(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_HID, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 
     void SetPalmaBoostMode(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_HID, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_HID, "(STUBBED) called");
     }
 };
 

src/core/hle/service/hid/irs.cpp

@@ -44,115 +44,133 @@ IRS::IRS() : ServiceFramework{"irs"} {
 }
 
 void IRS::ActivateIrsensor(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::DeactivateIrsensor(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::GetIrsensorSharedMemoryHandle(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_IRS, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushCopyObjects(shared_mem);
-    LOG_DEBUG(Service_IRS, "called");
 }
 
 void IRS::StopImageProcessor(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::RunMomentProcessor(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::RunClusteringProcessor(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::RunImageTransferProcessor(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::GetImageTransferProcessorState(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 5};
     rb.Push(RESULT_SUCCESS);
     rb.PushRaw<u64>(CoreTiming::GetTicks());
     rb.PushRaw<u32>(0);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::RunTeraPluginProcessor(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::GetNpadIrCameraHandle(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.PushRaw<u32>(device_handle);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::RunPointingProcessor(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::SuspendImageProcessor(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::CheckFirmwareVersion(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::SetFunctionLevel(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::RunImageTransferExProcessor(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::RunIrLedProcessor(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::StopImageProcessorAsync(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 void IRS::ActivateIrsensorWithFunctionLevel(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service_IRS, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_WARNING(Service_IRS, "(STUBBED) called");
 }
 
 IRS::~IRS() = default;

src/core/hle/service/lbl/lbl.cpp

@@ -55,29 +55,29 @@ public:
 
 private:
     void EnableVrMode(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_LBL, "called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
 
         vr_mode_enabled = true;
-
-        LOG_DEBUG(Service_LBL, "called");
     }
 
     void DisableVrMode(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_LBL, "called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
 
         vr_mode_enabled = false;
-
-        LOG_DEBUG(Service_LBL, "called");
     }
 
     void IsVrModeEnabled(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_LBL, "called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push(vr_mode_enabled);
-
-        LOG_DEBUG(Service_LBL, "called");
     }
 
     bool vr_mode_enabled = false;

src/core/hle/service/ldn/ldn.cpp

@@ -44,11 +44,11 @@ public:
     }
 
     void CreateMonitorService(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_LDN, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IMonitorService>();
-
-        LOG_DEBUG(Service_LDN, "called");
     }
 };
 
@@ -104,11 +104,11 @@ public:
     }
 
     void CreateSystemLocalCommunicationService(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_LDN, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ILocalCommunicationService>("ISystemLocalCommunicationService");
-
-        LOG_DEBUG(Service_LDN, "called");
     }
 };
 
@@ -125,11 +125,11 @@ public:
     }
 
     void CreateUserLocalCommunicationService(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_LDN, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ILocalCommunicationService>("IUserLocalCommunicationService");
-
-        LOG_DEBUG(Service_LDN, "called");
     }
 };
 

src/core/hle/service/ldr/ldr.cpp

@@ -97,6 +97,8 @@ public:
         rp.Skip(2, false);
         const VAddr nrr_addr{rp.Pop<VAddr>()};
         const u64 nrr_size{rp.Pop<u64>()};
+        LOG_DEBUG(Service_LDR, "called with nrr_addr={:016X}, nrr_size={:016X}", nrr_addr,
+                  nrr_size);
 
         if (!initialized) {
             LOG_ERROR(Service_LDR, "LDR:RO not initialized before use!");
@@ -189,6 +191,7 @@ public:
         IPC::RequestParser rp{ctx};
         rp.Skip(2, false);
         const auto nrr_addr{rp.Pop<VAddr>()};
+        LOG_DEBUG(Service_LDR, "called with nrr_addr={:016X}", nrr_addr);
 
         if (!Common::Is4KBAligned(nrr_addr)) {
             LOG_ERROR(Service_LDR, "NRR Address has invalid alignment (actual {:016X})!", nrr_addr);
@@ -219,6 +222,10 @@ public:
         const u64 nro_size{rp.Pop<u64>()};
         const VAddr bss_addr{rp.Pop<VAddr>()};
         const u64 bss_size{rp.Pop<u64>()};
+        LOG_DEBUG(
+            Service_LDR,
+            "called with nro_addr={:016X}, nro_size={:016X}, bss_addr={:016X}, bss_size={:016X}",
+            nro_addr, nro_size, bss_addr, bss_size);
 
         if (!initialized) {
             LOG_ERROR(Service_LDR, "LDR:RO not initialized before use!");
@@ -345,6 +352,8 @@ public:
         rp.Skip(2, false);
         const VAddr mapped_addr{rp.PopRaw<VAddr>()};
         const VAddr heap_addr{rp.PopRaw<VAddr>()};
+        LOG_DEBUG(Service_LDR, "called with mapped_addr={:016X}, heap_addr={:016X}", mapped_addr,
+                  heap_addr);
 
         if (!initialized) {
             LOG_ERROR(Service_LDR, "LDR:RO not initialized before use!");
@@ -393,11 +402,12 @@ public:
     }
 
     void Initialize(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_LDR, "(STUBBED) called");
+
         initialized = true;
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_LDR, "(STUBBED) called");
     }
 
 private:

src/core/hle/service/lm/lm.cpp

@@ -209,11 +209,11 @@ public:
      *      0: ResultCode
      */
     void OpenLogger(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_LM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ILogger>();
-
-        LOG_DEBUG(Service_LM, "called");
     }
 };
 

src/core/hle/service/mm/mm_u.cpp

@@ -31,12 +31,14 @@ public:
 private:
     void Initialize(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_MM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
 
     void Finalize(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_MM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
@@ -45,15 +47,16 @@ private:
         IPC::RequestParser rp{ctx};
         min = rp.Pop<u32>();
         max = rp.Pop<u32>();
-        current = min;
-
         LOG_WARNING(Service_MM, "(STUBBED) called, min=0x{:X}, max=0x{:X}", min, max);
+
+        current = min;
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
 
     void Get(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_MM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push(current);
@@ -61,6 +64,7 @@ private:
 
     void InitializeWithId(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_MM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(id); // Any non zero value
@@ -68,6 +72,7 @@ private:
 
     void FinalizeWithId(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_MM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
@@ -77,16 +82,17 @@ private:
         u32 input_id = rp.Pop<u32>();
         min = rp.Pop<u32>();
         max = rp.Pop<u32>();
-        current = min;
-
         LOG_WARNING(Service_MM, "(STUBBED) called, input_id=0x{:X}, min=0x{:X}, max=0x{:X}",
                     input_id, min, max);
+
+        current = min;
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
 
     void GetWithId(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_MM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push(current);

src/core/hle/service/nfc/nfc.cpp

@@ -43,11 +43,11 @@ public:
 
 private:
     void CreateAmInterface(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NFC, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IAm>();
-
-        LOG_DEBUG(Service_NFC, "called");
     }
 };
 
@@ -91,11 +91,11 @@ public:
 
 private:
     void CreateUserInterface(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NFC, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<MFIUser>();
-
-        LOG_DEBUG(Service_NFC, "called");
     }
 };
 
@@ -138,19 +138,19 @@ private:
     };
 
     void InitializeOld(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NFC, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0};
         rb.Push(RESULT_SUCCESS);
-
         // We don't deal with hardware initialization so we can just stub this.
-        LOG_DEBUG(Service_NFC, "called");
     }
 
     void IsNfcEnabledOld(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NFC, "IsNfcEnabledOld");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.PushRaw<u8>(Settings::values.enable_nfc);
-
-        LOG_DEBUG(Service_NFC, "IsNfcEnabledOld");
     }
 
     void GetStateOld(Kernel::HLERequestContext& ctx) {
@@ -183,11 +183,11 @@ public:
 
 private:
     void CreateUserInterface(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NFC, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IUser>();
-
-        LOG_DEBUG(Service_NFC, "called");
     }
 };
 
@@ -241,11 +241,11 @@ public:
 
 private:
     void CreateSystemInterface(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NFC, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ISystem>();
-
-        LOG_DEBUG(Service_NFC, "called");
     }
 };
 

src/core/hle/service/nfp/nfp.cpp

@@ -108,30 +108,29 @@ private:
     static_assert(sizeof(CommonInfo) == 0x40, "CommonInfo is an invalid size");
 
     void Initialize(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NFC, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0};
         rb.Push(RESULT_SUCCESS);
 
         state = State::Initialized;
-
-        LOG_DEBUG(Service_NFC, "called");
     }
 
     void GetState(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NFC, "called");
+
         IPC::ResponseBuilder rb{ctx, 3, 0};
         rb.Push(RESULT_SUCCESS);
         rb.PushRaw<u32>(static_cast<u32>(state));
-
-        LOG_DEBUG(Service_NFC, "called");
     }
 
     void ListDevices(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         const u32 array_size = rp.Pop<u32>();
+        LOG_DEBUG(Service_NFP, "called, array_size={}", array_size);
 
         ctx.WriteBuffer(&device_handle, sizeof(device_handle));
 
-        LOG_DEBUG(Service_NFP, "called, array_size={}", array_size);
-
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(1);
@@ -141,6 +140,7 @@ private:
         IPC::RequestParser rp{ctx};
         const u64 dev_handle = rp.Pop<u64>();
         LOG_DEBUG(Service_NFP, "called, dev_handle=0x{:X}", dev_handle);
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(npad_id);
@@ -150,6 +150,7 @@ private:
         IPC::RequestParser rp{ctx};
         const u64 dev_handle = rp.Pop<u64>();
         LOG_DEBUG(Service_NFP, "called, dev_handle=0x{:X}", dev_handle);
+
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(nfp_interface.GetNFCEvent());
@@ -168,6 +169,7 @@ private:
 
     void StopDetection(Kernel::HLERequestContext& ctx) {
         LOG_DEBUG(Service_NFP, "called");
+
         switch (device_state) {
         case DeviceState::TagFound:
         case DeviceState::TagNearby:
@@ -185,6 +187,7 @@ private:
 
     void GetDeviceState(Kernel::HLERequestContext& ctx) {
         LOG_DEBUG(Service_NFP, "called");
+
         auto nfc_event = nfp_interface.GetNFCEvent();
         if (!nfc_event->ShouldWait(Kernel::GetCurrentThread()) && !has_attached_handle) {
             device_state = DeviceState::TagFound;
@@ -323,6 +326,7 @@ private:
 
 void Module::Interface::CreateUserInterface(Kernel::HLERequestContext& ctx) {
     LOG_DEBUG(Service_NFP, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<IUser>(*this);

src/core/hle/service/nifm/nifm.cpp

@@ -63,12 +63,14 @@ public:
 private:
     void Submit(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_NIFM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
 
     void GetRequestState(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_NIFM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(0);
@@ -76,12 +78,14 @@ private:
 
     void GetResult(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_NIFM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
 
     void GetSystemEventReadableHandles(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_NIFM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2, 2};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(event1, event2);
@@ -89,12 +93,14 @@ private:
 
     void Cancel(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_NIFM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
 
     void SetConnectionConfirmationOption(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_NIFM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
@@ -122,32 +128,36 @@ private:
     void GetClientId(Kernel::HLERequestContext& ctx) {
         static constexpr u32 client_id = 1;
         LOG_WARNING(Service_NIFM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 4};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u64>(client_id); // Client ID needs to be non zero otherwise it's considered invalid
     }
     void CreateScanRequest(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NIFM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
 
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IScanRequest>();
-
-        LOG_DEBUG(Service_NIFM, "called");
     }
     void CreateRequest(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NIFM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
 
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IRequest>();
-
-        LOG_DEBUG(Service_NIFM, "called");
     }
     void RemoveNetworkProfile(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_NIFM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
     void CreateTemporaryNetworkProfile(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NIFM, "called");
+
         ASSERT_MSG(ctx.GetReadBufferSize() == 0x17c, "NetworkProfileData is not the correct size");
         u128 uuid{};
         auto buffer = ctx.ReadBuffer();
@@ -158,23 +168,24 @@ private:
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<INetworkProfile>();
         rb.PushRaw<u128>(uuid);
-
-        LOG_DEBUG(Service_NIFM, "called");
     }
     void IsWirelessCommunicationEnabled(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_NIFM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u8>(0);
     }
     void IsEthernetCommunicationEnabled(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_NIFM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u8>(0);
     }
     void IsAnyInternetRequestAccepted(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_NIFM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u8>(0);
@@ -235,17 +246,19 @@ public:
     }
 
     void CreateGeneralServiceOld(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NIFM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IGeneralService>();
-        LOG_DEBUG(Service_NIFM, "called");
     }
 
     void CreateGeneralService(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NIFM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IGeneralService>();
-        LOG_DEBUG(Service_NIFM, "called");
     }
 };
 

src/core/hle/service/nim/nim.cpp

@@ -148,47 +148,53 @@ private:
 
     void StartTask(Kernel::HLERequestContext& ctx) {
         // No need to connect to the internet, just finish the task straight away.
+        LOG_DEBUG(Service_NIM, "called");
+
         finished_event->Signal();
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_NIM, "called");
     }
 
     void GetFinishNotificationEvent(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NIM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(finished_event);
-        LOG_DEBUG(Service_NIM, "called");
     }
 
     void GetResult(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NIM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_NIM, "called");
     }
 
     void Cancel(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NIM, "called");
+
         finished_event->Clear();
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_DEBUG(Service_NIM, "called");
     }
 
     void IsProcessing(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NIM, "called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.PushRaw<u32>(0); // We instantly process the request
-        LOG_DEBUG(Service_NIM, "called");
     }
 
     void GetServerTime(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NIM, "called");
+
         const s64 server_time{std::chrono::duration_cast<std::chrono::seconds>(
                                   std::chrono::system_clock::now().time_since_epoch())
                                   .count()};
         IPC::ResponseBuilder rb{ctx, 4};
         rb.Push(RESULT_SUCCESS);
         rb.PushRaw<s64>(server_time);
-        LOG_DEBUG(Service_NIM, "called");
     }
 };
 
@@ -208,23 +214,26 @@ public:
 
 private:
     void OpenEnsureNetworkClockAvailabilityService(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NIM, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IEnsureNetworkClockAvailabilityService>();
-        LOG_DEBUG(Service_NIM, "called");
     }
 
     // TODO(ogniK): Do we need these?
     void SuspendAutonomicTimeCorrection(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_NIM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_NIM, "(STUBBED) called");
     }
 
     void ResumeAutonomicTimeCorrection(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_NIM, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
-        LOG_WARNING(Service_NIM, "(STUBBED) called");
     }
 };
 

src/core/hle/service/ns/ns.cpp

@@ -433,11 +433,11 @@ public:
 private:
     template <typename T>
     void PushInterface(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NS, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<T>();
-
-        LOG_DEBUG(Service_NS, "called");
     }
 };
 
@@ -526,11 +526,11 @@ public:
 
 private:
     void OpenSystemUpdateControl(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_NS, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<ISystemUpdateControl>();
-
-        LOG_DEBUG(Service_NS, "called");
     }
 };
 

src/core/hle/service/ns/pl_u.cpp

@@ -281,6 +281,7 @@ void PL_U::RequestLoad(Kernel::HLERequestContext& ctx) {
     const u32 shared_font_type{rp.Pop<u32>()};
     // Games don't call this so all fonts should be loaded
     LOG_DEBUG(Service_NS, "called, shared_font_type={}", shared_font_type);
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
 }
@@ -288,8 +289,8 @@ void PL_U::RequestLoad(Kernel::HLERequestContext& ctx) {
 void PL_U::GetLoadState(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
     const u32 font_id{rp.Pop<u32>()};
-
     LOG_DEBUG(Service_NS, "called, font_id={}", font_id);
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push<u32>(static_cast<u32>(LoadState::Done));
@@ -298,8 +299,8 @@ void PL_U::GetLoadState(Kernel::HLERequestContext& ctx) {
 void PL_U::GetSize(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
     const u32 font_id{rp.Pop<u32>()};
-
     LOG_DEBUG(Service_NS, "called, font_id={}", font_id);
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push<u32>(impl->GetSharedFontRegion(font_id).size);
@@ -308,8 +309,8 @@ void PL_U::GetSize(Kernel::HLERequestContext& ctx) {
 void PL_U::GetSharedMemoryAddressOffset(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
     const u32 font_id{rp.Pop<u32>()};
-
     LOG_DEBUG(Service_NS, "called, font_id={}", font_id);
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push<u32>(impl->GetSharedFontRegion(font_id).offset);
@@ -317,6 +318,7 @@ void PL_U::GetSharedMemoryAddressOffset(Kernel::HLERequestContext& ctx) {
 
 void PL_U::GetSharedMemoryNativeHandle(Kernel::HLERequestContext& ctx) {
     // Map backing memory for the font data
+    LOG_DEBUG(Service_NS, "called");
     Core::CurrentProcess()->VMManager().MapMemoryBlock(SHARED_FONT_MEM_VADDR, impl->shared_font, 0,
                                                        SHARED_FONT_MEM_SIZE,
                                                        Kernel::MemoryState::Shared);
@@ -328,7 +330,6 @@ void PL_U::GetSharedMemoryNativeHandle(Kernel::HLERequestContext& ctx) {
         Kernel::MemoryPermission::Read, SHARED_FONT_MEM_VADDR, Kernel::MemoryRegion::BASE,
         "PL_U:shared_font_mem");
 
-    LOG_DEBUG(Service_NS, "called");
     IPC::ResponseBuilder rb{ctx, 2, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushCopyObjects(impl->shared_font_mem);
@@ -338,6 +339,7 @@ void PL_U::GetSharedFontInOrderOfPriority(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
     const u64 language_code{rp.Pop<u64>()}; // TODO(ogniK): Find out what this is used for
     LOG_DEBUG(Service_NS, "called, language_code={:X}", language_code);
+
     IPC::ResponseBuilder rb{ctx, 4};
     std::vector<u32> font_codes;
     std::vector<u32> font_offsets;

src/core/hle/service/nvdrv/devices/nvhost_as_gpu.cpp

@@ -54,6 +54,7 @@ u32 nvhost_as_gpu::InitalizeEx(const std::vector<u8>& input, std::vector<u8>& ou
     IoctlInitalizeEx params{};
     std::memcpy(&params, input.data(), input.size());
     LOG_WARNING(Service_NVDRV, "(STUBBED) called, big_page_size=0x{:X}", params.big_page_size);
+
     return 0;
 }
 
@@ -191,6 +192,7 @@ u32 nvhost_as_gpu::BindChannel(const std::vector<u8>& input, std::vector<u8>& ou
     IoctlBindChannel params{};
     std::memcpy(&params, input.data(), input.size());
     LOG_DEBUG(Service_NVDRV, "called, fd={:X}", params.fd);
+
     channel = params.fd;
     return 0;
 }

src/core/hle/service/nvdrv/devices/nvhost_ctrl_gpu.cpp

@@ -103,6 +103,7 @@ u32 nvhost_ctrl_gpu::GetTPCMasks(const std::vector<u8>& input, std::vector<u8>&
 
 u32 nvhost_ctrl_gpu::GetActiveSlotMask(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_DEBUG(Service_NVDRV, "called");
+
     IoctlActiveSlotMask params{};
     if (input.size() > 0) {
         std::memcpy(&params, input.data(), input.size());
@@ -115,6 +116,7 @@ u32 nvhost_ctrl_gpu::GetActiveSlotMask(const std::vector<u8>& input, std::vector
 
 u32 nvhost_ctrl_gpu::ZCullGetCtxSize(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_DEBUG(Service_NVDRV, "called");
+
     IoctlZcullGetCtxSize params{};
     if (input.size() > 0) {
         std::memcpy(&params, input.data(), input.size());
@@ -126,6 +128,7 @@ u32 nvhost_ctrl_gpu::ZCullGetCtxSize(const std::vector<u8>& input, std::vector<u
 
 u32 nvhost_ctrl_gpu::ZCullGetInfo(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_DEBUG(Service_NVDRV, "called");
+
     IoctlNvgpuGpuZcullGetInfoArgs params{};
 
     if (input.size() > 0) {
@@ -148,6 +151,7 @@ u32 nvhost_ctrl_gpu::ZCullGetInfo(const std::vector<u8>& input, std::vector<u8>&
 
 u32 nvhost_ctrl_gpu::ZBCSetTable(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_WARNING(Service_NVDRV, "(STUBBED) called");
+
     IoctlZbcSetTable params{};
     std::memcpy(&params, input.data(), input.size());
     // TODO(ogniK): What does this even actually do?
@@ -157,6 +161,7 @@ u32 nvhost_ctrl_gpu::ZBCSetTable(const std::vector<u8>& input, std::vector<u8>&
 
 u32 nvhost_ctrl_gpu::ZBCQueryTable(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_WARNING(Service_NVDRV, "(STUBBED) called");
+
     IoctlZbcQueryTable params{};
     std::memcpy(&params, input.data(), input.size());
     // TODO : To implement properly
@@ -166,6 +171,7 @@ u32 nvhost_ctrl_gpu::ZBCQueryTable(const std::vector<u8>& input, std::vector<u8>
 
 u32 nvhost_ctrl_gpu::FlushL2(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_WARNING(Service_NVDRV, "(STUBBED) called");
+
     IoctlFlushL2 params{};
     std::memcpy(&params, input.data(), input.size());
     // TODO : To implement properly
@@ -175,6 +181,7 @@ u32 nvhost_ctrl_gpu::FlushL2(const std::vector<u8>& input, std::vector<u8>& outp
 
 u32 nvhost_ctrl_gpu::GetGpuTime(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_DEBUG(Service_NVDRV, "called");
+
     IoctlGetGpuTime params{};
     std::memcpy(&params, input.data(), input.size());
     params.gpu_time = CoreTiming::cyclesToNs(CoreTiming::GetTicks());

src/core/hle/service/nvdrv/devices/nvhost_gpu.cpp

@@ -8,7 +8,6 @@
 #include "core/core.h"
 #include "core/hle/service/nvdrv/devices/nvhost_gpu.h"
 #include "core/memory.h"
-#include "video_core/command_processor.h"
 #include "video_core/gpu.h"
 #include "video_core/memory_manager.h"
 
@@ -61,12 +60,14 @@ u32 nvhost_gpu::SetNVMAPfd(const std::vector<u8>& input, std::vector<u8>& output
     IoctlSetNvmapFD params{};
     std::memcpy(&params, input.data(), input.size());
     LOG_DEBUG(Service_NVDRV, "called, fd={}", params.nvmap_fd);
+
     nvmap_fd = params.nvmap_fd;
     return 0;
 }
 
 u32 nvhost_gpu::SetClientData(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_DEBUG(Service_NVDRV, "called");
+
     IoctlClientData params{};
     std::memcpy(&params, input.data(), input.size());
     user_data = params.data;
@@ -75,6 +76,7 @@ u32 nvhost_gpu::SetClientData(const std::vector<u8>& input, std::vector<u8>& out
 
 u32 nvhost_gpu::GetClientData(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_DEBUG(Service_NVDRV, "called");
+
     IoctlClientData params{};
     std::memcpy(&params, input.data(), input.size());
     params.data = user_data;
@@ -86,6 +88,7 @@ u32 nvhost_gpu::ZCullBind(const std::vector<u8>& input, std::vector<u8>& output)
     std::memcpy(&zcull_params, input.data(), input.size());
     LOG_DEBUG(Service_NVDRV, "called, gpu_va={:X}, mode={:X}", zcull_params.gpu_va,
               zcull_params.mode);
+
     std::memcpy(output.data(), &zcull_params, output.size());
     return 0;
 }
@@ -95,6 +98,7 @@ u32 nvhost_gpu::SetErrorNotifier(const std::vector<u8>& input, std::vector<u8>&
     std::memcpy(&params, input.data(), input.size());
     LOG_WARNING(Service_NVDRV, "(STUBBED) called, offset={:X}, size={:X}, mem={:X}", params.offset,
                 params.size, params.mem);
+
     std::memcpy(output.data(), &params, output.size());
     return 0;
 }
@@ -102,6 +106,7 @@ u32 nvhost_gpu::SetErrorNotifier(const std::vector<u8>& input, std::vector<u8>&
 u32 nvhost_gpu::SetChannelPriority(const std::vector<u8>& input, std::vector<u8>& output) {
     std::memcpy(&channel_priority, input.data(), input.size());
     LOG_DEBUG(Service_NVDRV, "(STUBBED) called, priority={:X}", channel_priority);
+
     return 0;
 }
 
@@ -113,6 +118,7 @@ u32 nvhost_gpu::AllocGPFIFOEx2(const std::vector<u8>& input, std::vector<u8>& ou
                 "unk1={:X}, unk2={:X}, unk3={:X}",
                 params.num_entries, params.flags, params.unk0, params.unk1, params.unk2,
                 params.unk3);
+
     params.fence_out.id = 0;
     params.fence_out.value = 0;
     std::memcpy(output.data(), &params, output.size());
@@ -124,11 +130,18 @@ u32 nvhost_gpu::AllocateObjectContext(const std::vector<u8>& input, std::vector<
     std::memcpy(&params, input.data(), input.size());
     LOG_WARNING(Service_NVDRV, "(STUBBED) called, class_num={:X}, flags={:X}", params.class_num,
                 params.flags);
+
     params.obj_id = 0x0;
     std::memcpy(output.data(), &params, output.size());
     return 0;
 }
 
+static void PushGPUEntries(Tegra::CommandList&& entries) {
+    auto& dma_pusher{Core::System::GetInstance().GPU().DmaPusher()};
+    dma_pusher.Push(std::move(entries));
+    dma_pusher.DispatchCalls();
+}
+
 u32 nvhost_gpu::SubmitGPFIFO(const std::vector<u8>& input, std::vector<u8>& output) {
     if (input.size() < sizeof(IoctlSubmitGpfifo)) {
         UNIMPLEMENTED();
@@ -142,11 +155,11 @@ u32 nvhost_gpu::SubmitGPFIFO(const std::vector<u8>& input, std::vector<u8>& outp
                                    params.num_entries * sizeof(Tegra::CommandListHeader),
                "Incorrect input size");
 
-    std::vector<Tegra::CommandListHeader> entries(params.num_entries);
+    Tegra::CommandList entries(params.num_entries);
     std::memcpy(entries.data(), &input[sizeof(IoctlSubmitGpfifo)],
                 params.num_entries * sizeof(Tegra::CommandListHeader));
 
-    Core::System::GetInstance().GPU().ProcessCommandLists(entries);
+    PushGPUEntries(std::move(entries));
 
     params.fence_out.id = 0;
     params.fence_out.value = 0;
@@ -163,11 +176,11 @@ u32 nvhost_gpu::KickoffPB(const std::vector<u8>& input, std::vector<u8>& output)
     LOG_WARNING(Service_NVDRV, "(STUBBED) called, gpfifo={:X}, num_entries={:X}, flags={:X}",
                 params.address, params.num_entries, params.flags);
 
-    std::vector<Tegra::CommandListHeader> entries(params.num_entries);
+    Tegra::CommandList entries(params.num_entries);
     Memory::ReadBlock(params.address, entries.data(),
                       params.num_entries * sizeof(Tegra::CommandListHeader));
 
-    Core::System::GetInstance().GPU().ProcessCommandLists(entries);
+    PushGPUEntries(std::move(entries));
 
     params.fence_out.id = 0;
     params.fence_out.value = 0;
@@ -179,6 +192,7 @@ u32 nvhost_gpu::GetWaitbase(const std::vector<u8>& input, std::vector<u8>& outpu
     IoctlGetWaitbase params{};
     std::memcpy(&params, input.data(), sizeof(IoctlGetWaitbase));
     LOG_INFO(Service_NVDRV, "called, unknown=0x{:X}", params.unknown);
+
     params.value = 0; // Seems to be hard coded at 0
     std::memcpy(output.data(), &params, output.size());
     return 0;
@@ -188,6 +202,7 @@ u32 nvhost_gpu::ChannelSetTimeout(const std::vector<u8>& input, std::vector<u8>&
     IoctlChannelSetTimeout params{};
     std::memcpy(&params, input.data(), sizeof(IoctlChannelSetTimeout));
     LOG_INFO(Service_NVDRV, "called, timeout=0x{:X}", params.timeout);
+
     return 0;
 }
 

src/core/hle/service/nvdrv/devices/nvhost_nvdec.cpp

@@ -30,6 +30,7 @@ u32 nvhost_nvdec::SetNVMAPfd(const std::vector<u8>& input, std::vector<u8>& outp
     IoctlSetNvmapFD params{};
     std::memcpy(&params, input.data(), input.size());
     LOG_DEBUG(Service_NVDRV, "called, fd={}", params.nvmap_fd);
+
     nvmap_fd = params.nvmap_fd;
     return 0;
 }

src/core/hle/service/nvdrv/devices/nvhost_nvjpg.cpp

@@ -30,6 +30,7 @@ u32 nvhost_nvjpg::SetNVMAPfd(const std::vector<u8>& input, std::vector<u8>& outp
     IoctlSetNvmapFD params{};
     std::memcpy(&params, input.data(), input.size());
     LOG_DEBUG(Service_NVDRV, "called, fd={}", params.nvmap_fd);
+
     nvmap_fd = params.nvmap_fd;
     return 0;
 }

src/core/hle/service/nvdrv/devices/nvhost_vic.cpp

@@ -30,6 +30,7 @@ u32 nvhost_vic::SetNVMAPfd(const std::vector<u8>& input, std::vector<u8>& output
     IoctlSetNvmapFD params{};
     std::memcpy(&params, input.data(), input.size());
     LOG_DEBUG(Service_NVDRV, "called, fd={}", params.nvmap_fd);
+
     nvmap_fd = params.nvmap_fd;
     return 0;
 }

src/core/hle/service/nvdrv/devices/nvmap.cpp

@@ -54,6 +54,7 @@ u32 nvmap::IocCreate(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_DEBUG(Service_NVDRV, "size=0x{:08X}", params.size);
 
     if (!params.size) {
+        LOG_ERROR(Service_NVDRV, "Size is 0");
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
     // Create a new nvmap object and obtain a handle to it.
@@ -78,10 +79,12 @@ u32 nvmap::IocAlloc(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_DEBUG(Service_NVDRV, "called, addr={:X}", params.addr);
 
     if (!params.handle) {
+        LOG_ERROR(Service_NVDRV, "Handle is 0");
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
 
     if ((params.align - 1) & params.align) {
+        LOG_ERROR(Service_NVDRV, "Incorrect alignment used, alignment={:08X}", params.align);
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
 
@@ -92,10 +95,12 @@ u32 nvmap::IocAlloc(const std::vector<u8>& input, std::vector<u8>& output) {
 
     auto object = GetObject(params.handle);
     if (!object) {
+        LOG_ERROR(Service_NVDRV, "Object does not exist, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
 
     if (object->status == Object::Status::Allocated) {
+        LOG_ERROR(Service_NVDRV, "Object is already allocated, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::OperationNotPermitted);
     }
 
@@ -116,11 +121,13 @@ u32 nvmap::IocGetId(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_WARNING(Service_NVDRV, "called");
 
     if (!params.handle) {
+        LOG_ERROR(Service_NVDRV, "Handle is zero");
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
 
     auto object = GetObject(params.handle);
     if (!object) {
+        LOG_ERROR(Service_NVDRV, "Object does not exist, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::OperationNotPermitted);
     }
 
@@ -139,11 +146,13 @@ u32 nvmap::IocFromId(const std::vector<u8>& input, std::vector<u8>& output) {
     auto itr = std::find_if(handles.begin(), handles.end(),
                             [&](const auto& entry) { return entry.second->id == params.id; });
     if (itr == handles.end()) {
+        LOG_ERROR(Service_NVDRV, "Object does not exist, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
 
     auto& object = itr->second;
     if (object->status != Object::Status::Allocated) {
+        LOG_ERROR(Service_NVDRV, "Object is not allocated, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
 
@@ -166,10 +175,12 @@ u32 nvmap::IocParam(const std::vector<u8>& input, std::vector<u8>& output) {
 
     auto object = GetObject(params.handle);
     if (!object) {
+        LOG_ERROR(Service_NVDRV, "Object does not exist, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
 
     if (object->status != Object::Status::Allocated) {
+        LOG_ERROR(Service_NVDRV, "Object is not allocated, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::OperationNotPermitted);
     }
 
@@ -209,9 +220,14 @@ u32 nvmap::IocFree(const std::vector<u8>& input, std::vector<u8>& output) {
 
     auto itr = handles.find(params.handle);
     if (itr == handles.end()) {
+        LOG_ERROR(Service_NVDRV, "Object does not exist, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
     if (!itr->second->refcount) {
+        LOG_ERROR(
+            Service_NVDRV,
+            "There is no references to this object. The object is already freed. handle={:08X}",
+            params.handle);
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
 

src/core/hle/service/nvdrv/interface.cpp

@@ -55,6 +55,7 @@ void NVDRV::Close(Kernel::HLERequestContext& ctx) {
 
 void NVDRV::Initialize(Kernel::HLERequestContext& ctx) {
     LOG_WARNING(Service_NVDRV, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push<u32>(0);
@@ -75,8 +76,8 @@ void NVDRV::QueryEvent(Kernel::HLERequestContext& ctx) {
 void NVDRV::SetClientPID(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
     pid = rp.Pop<u64>();
-
     LOG_WARNING(Service_NVDRV, "(STUBBED) called, pid=0x{:X}", pid);
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push<u32>(0);
@@ -84,12 +85,14 @@ void NVDRV::SetClientPID(Kernel::HLERequestContext& ctx) {
 
 void NVDRV::FinishInitialize(Kernel::HLERequestContext& ctx) {
     LOG_WARNING(Service_NVDRV, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
 }
 
 void NVDRV::GetStatus(Kernel::HLERequestContext& ctx) {
     LOG_WARNING(Service_NVDRV, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
 }
@@ -98,6 +101,7 @@ void NVDRV::DumpGraphicsMemoryInfo(Kernel::HLERequestContext& ctx) {
     // According to SwitchBrew, this has no inputs and no outputs, so effectively does nothing on
     // retail hardware.
     LOG_DEBUG(Service_NVDRV, "called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
 }

src/core/hle/service/nvflinger/buffer_queue.cpp

@@ -20,13 +20,13 @@ BufferQueue::BufferQueue(u32 id, u64 layer_id) : id(id), layer_id(layer_id) {
 BufferQueue::~BufferQueue() = default;
 
 void BufferQueue::SetPreallocatedBuffer(u32 slot, const IGBPBuffer& igbp_buffer) {
+    LOG_WARNING(Service, "Adding graphics buffer {}", slot);
+
     Buffer buffer{};
     buffer.slot = slot;
     buffer.igbp_buffer = igbp_buffer;
     buffer.status = Buffer::Status::Free;
 
-    LOG_WARNING(Service, "Adding graphics buffer {}", slot);
-
     queue.emplace_back(buffer);
     buffer_wait_event->Signal();
 }
@@ -92,6 +92,7 @@ void BufferQueue::ReleaseBuffer(u32 slot) {
 
 u32 BufferQueue::Query(QueryType type) {
     LOG_WARNING(Service, "(STUBBED) called type={}", static_cast<u32>(type));
+
     switch (type) {
     case QueryType::NativeWindowFormat:
         // TODO(Subv): Use an enum for this

src/core/hle/service/pctl/module.cpp

@@ -114,29 +114,33 @@ public:
 private:
     void Initialize(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_PCTL, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 0};
         rb.Push(RESULT_SUCCESS);
     }
 
     void CheckFreeCommunicationPermission(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_PCTL, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
 };
 
 void Module::Interface::CreateService(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_PCTL, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<IParentalControlService>();
-    LOG_DEBUG(Service_PCTL, "called");
 }
 
 void Module::Interface::CreateServiceWithoutInitialize(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_PCTL, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<IParentalControlService>();
-    LOG_DEBUG(Service_PCTL, "called");
 }
 
 Module::Interface::Interface(std::shared_ptr<Module> module, const char* name)

src/core/hle/service/pm/pm.cpp

@@ -20,11 +20,11 @@ public:
 
 private:
     void GetBootMode(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_PM, "called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(static_cast<u32>(SystemBootMode::Normal)); // Normal boot mode
-
-        LOG_DEBUG(Service_PM, "called");
     }
 };
 

src/core/hle/service/psc/psc.cpp

@@ -61,11 +61,11 @@ public:
 
 private:
     void GetPmModule(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_PSC, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IPmModule>();
-
-        LOG_DEBUG(Service_PSC, "called");
     }
 };
 

src/core/hle/service/set/set.cpp

@@ -35,6 +35,8 @@ constexpr std::array<LanguageCode, 17> available_language_codes = {{
 constexpr std::size_t pre4_0_0_max_entries = 0xF;
 constexpr std::size_t post4_0_0_max_entries = 0x40;
 
+constexpr ResultCode ERR_INVALID_LANGUAGE{ErrorModule::Settings, 625};
+
 LanguageCode GetLanguageCodeFromIndex(std::size_t index) {
     return available_language_codes.at(index);
 }
@@ -49,38 +51,54 @@ static std::array<LanguageCode, size> MakeLanguageCodeSubset() {
 static void PushResponseLanguageCode(Kernel::HLERequestContext& ctx, std::size_t max_size) {
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
-    if (available_language_codes.size() > max_size)
+    if (available_language_codes.size() > max_size) {
         rb.Push(static_cast<u32>(max_size));
-    else
+    } else {
         rb.Push(static_cast<u32>(available_language_codes.size()));
+    }
 }
 
 void SET::GetAvailableLanguageCodes(Kernel::HLERequestContext& ctx) {
-    if (available_language_codes.size() > pre4_0_0_max_entries)
-        ctx.WriteBuffer(MakeLanguageCodeSubset<pre4_0_0_max_entries>());
-    else
-        ctx.WriteBuffer(available_language_codes);
-
-    PushResponseLanguageCode(ctx, pre4_0_0_max_entries);
-
     LOG_DEBUG(Service_SET, "called");
+
+    if (available_language_codes.size() > pre4_0_0_max_entries) {
+        ctx.WriteBuffer(MakeLanguageCodeSubset<pre4_0_0_max_entries>());
+    } else {
+        ctx.WriteBuffer(available_language_codes);
+    }
+    PushResponseLanguageCode(ctx, pre4_0_0_max_entries);
+}
+
+void SET::MakeLanguageCode(Kernel::HLERequestContext& ctx) {
+    IPC::RequestParser rp{ctx};
+    const auto index = rp.Pop<u32>();
+
+    if (index >= available_language_codes.size()) {
+        IPC::ResponseBuilder rb{ctx, 2};
+        rb.Push(ERR_INVALID_LANGUAGE);
+        return;
+    }
+
+    IPC::ResponseBuilder rb{ctx, 4};
+    rb.Push(RESULT_SUCCESS);
+    rb.PushEnum(available_language_codes[index]);
 }
 
 void SET::GetAvailableLanguageCodes2(Kernel::HLERequestContext& ctx) {
-    if (available_language_codes.size() > post4_0_0_max_entries)
-        ctx.WriteBuffer(MakeLanguageCodeSubset<post4_0_0_max_entries>());
-    else
-        ctx.WriteBuffer(available_language_codes);
-
-    PushResponseLanguageCode(ctx, post4_0_0_max_entries);
-
     LOG_DEBUG(Service_SET, "called");
+
+    if (available_language_codes.size() > post4_0_0_max_entries) {
+        ctx.WriteBuffer(MakeLanguageCodeSubset<post4_0_0_max_entries>());
+    } else {
+        ctx.WriteBuffer(available_language_codes);
+    }
+    PushResponseLanguageCode(ctx, post4_0_0_max_entries);
 }
 
 void SET::GetAvailableLanguageCodeCount(Kernel::HLERequestContext& ctx) {
-    PushResponseLanguageCode(ctx, pre4_0_0_max_entries);
-
     LOG_DEBUG(Service_SET, "called");
+
+    PushResponseLanguageCode(ctx, pre4_0_0_max_entries);
 }
 
 void SET::GetAvailableLanguageCodeCount2(Kernel::HLERequestContext& ctx) {
@@ -90,18 +108,18 @@ void SET::GetAvailableLanguageCodeCount2(Kernel::HLERequestContext& ctx) {
 }
 
 void SET::GetLanguageCode(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_SET, "called {}", Settings::values.language_index);
+
     IPC::ResponseBuilder rb{ctx, 4};
     rb.Push(RESULT_SUCCESS);
-    rb.Push(static_cast<u64>(available_language_codes[Settings::values.language_index]));
-
-    LOG_DEBUG(Service_SET, "called {}", Settings::values.language_index);
+    rb.PushEnum(available_language_codes[Settings::values.language_index]);
 }
 
 SET::SET() : ServiceFramework("set") {
     static const FunctionInfo functions[] = {
         {0, &SET::GetLanguageCode, "GetLanguageCode"},
         {1, &SET::GetAvailableLanguageCodes, "GetAvailableLanguageCodes"},
-        {2, nullptr, "MakeLanguageCode"},
+        {2, &SET::MakeLanguageCode, "MakeLanguageCode"},
         {3, &SET::GetAvailableLanguageCodeCount, "GetAvailableLanguageCodeCount"},
         {4, nullptr, "GetRegionCode"},
         {5, &SET::GetAvailableLanguageCodes2, "GetAvailableLanguageCodes2"},

src/core/hle/service/set/set.h

@@ -38,6 +38,7 @@ public:
 private:
     void GetLanguageCode(Kernel::HLERequestContext& ctx);
     void GetAvailableLanguageCodes(Kernel::HLERequestContext& ctx);
+    void MakeLanguageCode(Kernel::HLERequestContext& ctx);
     void GetAvailableLanguageCodes2(Kernel::HLERequestContext& ctx);
     void GetAvailableLanguageCodeCount(Kernel::HLERequestContext& ctx);
     void GetAvailableLanguageCodeCount2(Kernel::HLERequestContext& ctx);

src/core/hle/service/set/set_sys.cpp

@@ -10,22 +10,22 @@
 namespace Service::Set {
 
 void SET_SYS::GetColorSetId(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_SET, "called");
+
     IPC::ResponseBuilder rb{ctx, 3};
 
     rb.Push(RESULT_SUCCESS);
     rb.PushEnum(color_set);
-
-    LOG_DEBUG(Service_SET, "called");
 }
 
 void SET_SYS::SetColorSetId(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_SET, "called");
+
     IPC::RequestParser rp{ctx};
     color_set = rp.PopEnum<ColorSet>();
 
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-
-    LOG_DEBUG(Service_SET, "called");
 }
 
 SET_SYS::SET_SYS() : ServiceFramework("set:sys") {

src/core/hle/service/sm/controller.cpp

@@ -14,25 +14,26 @@ namespace Service::SM {
 
 void Controller::ConvertSessionToDomain(Kernel::HLERequestContext& ctx) {
     ASSERT_MSG(ctx.Session()->IsSession(), "Session is already a domain");
+    LOG_DEBUG(Service, "called, server_session={}", ctx.Session()->GetObjectId());
     ctx.Session()->ConvertToDomain();
 
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push<u32>(1); // Converted sessions start with 1 request handler
-
-    LOG_DEBUG(Service, "called, server_session={}", ctx.Session()->GetObjectId());
 }
 
 void Controller::DuplicateSession(Kernel::HLERequestContext& ctx) {
     // TODO(bunnei): This is just creating a new handle to the same Session. I assume this is wrong
     // and that we probably want to actually make an entirely new Session, but we still need to
     // verify this on hardware.
+    LOG_DEBUG(Service, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1, IPC::ResponseBuilder::Flags::AlwaysMoveHandles};
     rb.Push(RESULT_SUCCESS);
     Kernel::SharedPtr<Kernel::ClientSession> session{ctx.Session()->parent->client};
     rb.PushMoveObjects(session);
 
-    LOG_DEBUG(Service, "called, session={}", session->GetObjectId());
+    LOG_DEBUG(Service, "session={}", session->GetObjectId());
 }
 
 void Controller::DuplicateSessionEx(Kernel::HLERequestContext& ctx) {
@@ -42,11 +43,11 @@ void Controller::DuplicateSessionEx(Kernel::HLERequestContext& ctx) {
 }
 
 void Controller::QueryPointerBufferSize(Kernel::HLERequestContext& ctx) {
+    LOG_WARNING(Service, "(STUBBED) called");
+
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push<u16>(0x500);
-
-    LOG_WARNING(Service, "(STUBBED) called");
 }
 
 Controller::Controller() : ServiceFramework("IpcController") {

src/core/hle/service/sm/sm.cpp

@@ -103,9 +103,10 @@ SM::~SM() = default;
  *      0: ResultCode
  */
 void SM::Initialize(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_SM, "called");
+
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_DEBUG(Service_SM, "called");
 }
 
 void SM::GetService(Kernel::HLERequestContext& ctx) {
@@ -172,6 +173,7 @@ void SM::UnregisterService(Kernel::HLERequestContext& ctx) {
     const auto end = std::find(name_buf.begin(), name_buf.end(), '\0');
 
     const std::string name(name_buf.begin(), end);
+    LOG_DEBUG(Service_SM, "called with name={}", name);
 
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(service_manager->UnregisterService(name));

src/core/hle/service/spl/module.cpp

@@ -24,6 +24,8 @@ Module::Interface::Interface(std::shared_ptr<Module> module, const char* name)
 Module::Interface::~Interface() = default;
 
 void Module::Interface::GetRandomBytes(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_SPL, "called");
+
     IPC::RequestParser rp{ctx};
 
     std::size_t size = ctx.GetWriteBufferSize();
@@ -36,7 +38,6 @@ void Module::Interface::GetRandomBytes(Kernel::HLERequestContext& ctx) {
 
     IPC::ResponseBuilder rb{ctx, 2};
     rb.Push(RESULT_SUCCESS);
-    LOG_DEBUG(Service_SPL, "called");
 }
 
 void InstallInterfaces(SM::ServiceManager& service_manager) {

src/core/hle/service/ssl/ssl.cpp

@@ -69,6 +69,7 @@ public:
 private:
     void SetOption(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_SSL, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
 
         IPC::ResponseBuilder rb{ctx, 2};
@@ -114,6 +115,7 @@ private:
 
     void SetInterfaceVersion(Kernel::HLERequestContext& ctx) {
         LOG_DEBUG(Service_SSL, "called");
+
         IPC::RequestParser rp{ctx};
         ssl_version = rp.Pop<u32>();
 

src/core/hle/service/time/time.cpp

@@ -72,6 +72,7 @@ private:
                                        std::chrono::system_clock::now().time_since_epoch())
                                        .count()};
         LOG_DEBUG(Service_Time, "called");
+
         IPC::ResponseBuilder rb{ctx, 4};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u64>(time_since_epoch);
@@ -79,6 +80,7 @@ private:
 
     void GetSystemClockContext(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_Time, "(STUBBED) called");
+
         SystemClockContext system_clock_ontext{};
         IPC::ResponseBuilder rb{ctx, (sizeof(SystemClockContext) / 4) + 2};
         rb.Push(RESULT_SUCCESS);
@@ -98,6 +100,7 @@ public:
 private:
     void GetCurrentTimePoint(Kernel::HLERequestContext& ctx) {
         LOG_DEBUG(Service_Time, "called");
+
         SteadyClockTimePoint steady_clock_time_point{
             CoreTiming::cyclesToMs(CoreTiming::GetTicks()) / 1000};
         IPC::ResponseBuilder rb{ctx, (sizeof(SteadyClockTimePoint) / 4) + 2};
@@ -130,6 +133,7 @@ private:
 
     void GetDeviceLocationName(Kernel::HLERequestContext& ctx) {
         LOG_DEBUG(Service_Time, "called");
+
         IPC::ResponseBuilder rb{ctx, (sizeof(LocationName) / 4) + 2};
         rb.Push(RESULT_SUCCESS);
         rb.PushRaw(location_name);
@@ -137,6 +141,7 @@ private:
 
     void GetTotalLocationNameCount(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_Time, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 3};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u32>(0);
@@ -154,7 +159,6 @@ private:
     void ToCalendarTime(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         const u64 posix_time = rp.Pop<u64>();
-
         LOG_WARNING(Service_Time, "(STUBBED) called, posix_time=0x{:016X}", posix_time);
 
         TimeZoneRule time_zone_rule{};
@@ -175,7 +179,6 @@ private:
     void ToCalendarTimeWithMyRule(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         const u64 posix_time = rp.Pop<u64>();
-
         LOG_WARNING(Service_Time, "(STUBBED) called, posix_time=0x{:016X}", posix_time);
 
         CalendarTime calendar_time{2018, 1, 1, 0, 0, 0};
@@ -192,6 +195,7 @@ private:
     void ToPosixTime(Kernel::HLERequestContext& ctx) {
         // TODO(ogniK): Figure out how to handle multiple times
         LOG_WARNING(Service_Time, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         auto calendar_time = rp.PopRaw<CalendarTime>();
         auto posix_time = CalendarToPosix(calendar_time, {});
@@ -204,6 +208,7 @@ private:
 
     void ToPosixTimeWithMyRule(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_Time, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         auto calendar_time = rp.PopRaw<CalendarTime>();
         auto posix_time = CalendarToPosix(calendar_time, {});
@@ -216,38 +221,43 @@ private:
 };
 
 void Module::Interface::GetStandardUserSystemClock(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_Time, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<ISystemClock>();
-    LOG_DEBUG(Service_Time, "called");
 }
 
 void Module::Interface::GetStandardNetworkSystemClock(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_Time, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<ISystemClock>();
-    LOG_DEBUG(Service_Time, "called");
 }
 
 void Module::Interface::GetStandardSteadyClock(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_Time, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<ISteadyClock>();
-    LOG_DEBUG(Service_Time, "called");
 }
 
 void Module::Interface::GetTimeZoneService(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_Time, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<ITimeZoneService>();
-    LOG_DEBUG(Service_Time, "called");
 }
 
 void Module::Interface::GetStandardLocalSystemClock(Kernel::HLERequestContext& ctx) {
+    LOG_DEBUG(Service_Time, "called");
+
     IPC::ResponseBuilder rb{ctx, 2, 0, 1};
     rb.Push(RESULT_SUCCESS);
     rb.PushIpcInterface<ISystemClock>();
-    LOG_DEBUG(Service_Time, "called");
 }
 
 void Module::Interface::GetClockSnapshot(Kernel::HLERequestContext& ctx) {
@@ -265,6 +275,7 @@ void Module::Interface::GetClockSnapshot(Kernel::HLERequestContext& ctx) {
     const std::time_t time(time_since_epoch);
     const std::tm* tm = std::localtime(&time);
     if (tm == nullptr) {
+        LOG_ERROR(Service_Time, "tm is a nullptr");
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(ResultCode(-1)); // TODO(ogniK): Find appropriate error code
         return;

src/core/hle/service/usb/usb.cpp

@@ -159,11 +159,11 @@ public:
 
 private:
     void GetPdSession(Kernel::HLERequestContext& ctx) {
+        LOG_DEBUG(Service_USB, "called");
+
         IPC::ResponseBuilder rb{ctx, 2, 0, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushIpcInterface<IPdSession>();
-
-        LOG_DEBUG(Service_USB, "called");
     }
 };
 

src/core/hle/service/vi/vi.cpp

@@ -504,10 +504,10 @@ private:
         u32 id = rp.Pop<u32>();
         auto transaction = static_cast<TransactionId>(rp.Pop<u32>());
         u32 flags = rp.Pop<u32>();
-        auto buffer_queue = nv_flinger->GetBufferQueue(id);
-
         LOG_DEBUG(Service_VI, "called, transaction={:X}", static_cast<u32>(transaction));
 
+        auto buffer_queue = nv_flinger->GetBufferQueue(id);
+
         if (transaction == TransactionId::Connect) {
             IGBPConnectRequestParcel request{ctx.ReadBuffer()};
             IGBPConnectResponseParcel response{
@@ -593,9 +593,9 @@ private:
         u32 id = rp.Pop<u32>();
         s32 addval = rp.PopRaw<s32>();
         u32 type = rp.Pop<u32>();
-
         LOG_WARNING(Service_VI, "(STUBBED) called id={}, addval={:08X}, type={:08X}", id, addval,
                     type);
+
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
@@ -604,12 +604,11 @@ private:
         IPC::RequestParser rp{ctx};
         u32 id = rp.Pop<u32>();
         u32 unknown = rp.Pop<u32>();
+        LOG_WARNING(Service_VI, "(STUBBED) called id={}, unknown={:08X}", id, unknown);
 
         auto buffer_queue = nv_flinger->GetBufferQueue(id);
 
         // TODO(Subv): Find out what this actually is.
-
-        LOG_WARNING(Service_VI, "(STUBBED) called id={}, unknown={:08X}", id, unknown);
         IPC::ResponseBuilder rb{ctx, 2, 1};
         rb.Push(RESULT_SUCCESS);
         rb.PushCopyObjects(buffer_queue->GetBufferWaitEvent());
@@ -673,6 +672,7 @@ public:
 private:
     void SetLayerZ(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         u64 layer_id = rp.Pop<u64>();
         u64 z_value = rp.Pop<u64>();
@@ -685,13 +685,16 @@ private:
         IPC::RequestParser rp{ctx};
         u64 layer_id = rp.Pop<u64>();
         bool visibility = rp.Pop<bool>();
-        IPC::ResponseBuilder rb{ctx, 2};
-        rb.Push(RESULT_SUCCESS);
         LOG_WARNING(Service_VI, "(STUBBED) called, layer_id=0x{:08X}, visibility={}", layer_id,
                     visibility);
+
+        IPC::ResponseBuilder rb{ctx, 2};
+        rb.Push(RESULT_SUCCESS);
     }
 
     void GetDisplayMode(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_VI, "(STUBBED) called");
+
         IPC::ResponseBuilder rb{ctx, 6};
         rb.Push(RESULT_SUCCESS);
 
@@ -707,10 +710,8 @@ private:
                     static_cast<u32>(Settings::values.resolution_factor));
         }
 
-        rb.PushRaw<float>(60.0f);
+        rb.PushRaw<float>(60.0f); // This wouldn't seem to be correct for 30 fps games.
         rb.Push<u32>(0);
-
-        LOG_DEBUG(Service_VI, "called");
     }
 };
 
@@ -793,6 +794,7 @@ public:
 private:
     void CloseDisplay(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         u64 display = rp.Pop<u64>();
 
@@ -802,6 +804,7 @@ private:
 
     void CreateManagedLayer(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         u32 unknown = rp.Pop<u32>();
         rp.Skip(1, false);
@@ -817,6 +820,7 @@ private:
 
     void AddToLayerStack(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         u32 stack = rp.Pop<u32>();
         u64 layer_id = rp.Pop<u64>();
@@ -829,10 +833,11 @@ private:
         IPC::RequestParser rp{ctx};
         u64 layer_id = rp.Pop<u64>();
         bool visibility = rp.Pop<bool>();
-        IPC::ResponseBuilder rb{ctx, 2};
-        rb.Push(RESULT_SUCCESS);
         LOG_WARNING(Service_VI, "(STUBBED) called, layer_id=0x{:X}, visibility={}", layer_id,
                     visibility);
+
+        IPC::ResponseBuilder rb{ctx, 2};
+        rb.Push(RESULT_SUCCESS);
     }
 
     std::shared_ptr<NVFlinger::NVFlinger> nv_flinger;
@@ -878,6 +883,7 @@ private:
 
     void OpenDisplay(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         auto name_buf = rp.PopRaw<std::array<u8, 0x40>>();
         auto end = std::find(name_buf.begin(), name_buf.end(), '\0');
@@ -893,6 +899,7 @@ private:
 
     void CloseDisplay(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         u64 display_id = rp.Pop<u64>();
 
@@ -902,6 +909,7 @@ private:
 
     void GetDisplayResolution(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         u64 display_id = rp.Pop<u64>();
 
@@ -923,6 +931,7 @@ private:
 
     void SetLayerScalingMode(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         u32 scaling_mode = rp.Pop<u32>();
         u64 unknown = rp.Pop<u64>();
@@ -932,6 +941,8 @@ private:
     }
 
     void ListDisplays(Kernel::HLERequestContext& ctx) {
+        LOG_WARNING(Service_VI, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         DisplayInfo display_info;
         display_info.width *= static_cast<u64>(Settings::values.resolution_factor);
@@ -940,11 +951,11 @@ private:
         IPC::ResponseBuilder rb{ctx, 4};
         rb.Push(RESULT_SUCCESS);
         rb.Push<u64>(1);
-        LOG_WARNING(Service_VI, "(STUBBED) called");
     }
 
     void OpenLayer(Kernel::HLERequestContext& ctx) {
         LOG_DEBUG(Service_VI, "called");
+
         IPC::RequestParser rp{ctx};
         auto name_buf = rp.PopRaw<std::array<u8, 0x40>>();
         auto end = std::find(name_buf.begin(), name_buf.end(), '\0');
@@ -995,6 +1006,7 @@ private:
 
     void GetDisplayVsyncEvent(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
+
         IPC::RequestParser rp{ctx};
         u64 display_id = rp.Pop<u64>();
 

src/video_core/CMakeLists.txt

@@ -1,6 +1,6 @@
 add_library(video_core STATIC
-    command_processor.cpp
-    command_processor.h
+    dma_pusher.cpp
+    dma_pusher.h
     debug_utils/debug_utils.cpp
     debug_utils/debug_utils.h
     engines/fermi_2d.cpp

src/video_core/command_processor.h

@@ -1,53 +0,0 @@
-// Copyright 2018 yuzu Emulator Project
-// Licensed under GPLv2 or any later version
-// Refer to the license.txt file included.
-
-#pragma once
-
-#include <type_traits>
-#include "common/bit_field.h"
-#include "common/common_types.h"
-#include "video_core/memory_manager.h"
-
-namespace Tegra {
-
-enum class SubmissionMode : u32 {
-    IncreasingOld = 0,
-    Increasing = 1,
-    NonIncreasingOld = 2,
-    NonIncreasing = 3,
-    Inline = 4,
-    IncreaseOnce = 5
-};
-
-struct CommandListHeader {
-    u32 entry0; // gpu_va_lo
-    union {
-        u32 entry1; // gpu_va_hi | (unk_0x02 << 0x08) | (size << 0x0A) | (unk_0x01 << 0x1F)
-        BitField<0, 8, u32> gpu_va_hi;
-        BitField<8, 2, u32> unk1;
-        BitField<10, 21, u32> sz;
-        BitField<31, 1, u32> unk2;
-    };
-
-    GPUVAddr Address() const {
-        return (static_cast<GPUVAddr>(gpu_va_hi) << 32) | entry0;
-    }
-};
-static_assert(sizeof(CommandListHeader) == 8, "CommandListHeader is incorrect size");
-
-union CommandHeader {
-    u32 hex;
-
-    BitField<0, 13, u32> method;
-    BitField<13, 3, u32> subchannel;
-
-    BitField<16, 13, u32> arg_count;
-    BitField<16, 13, u32> inline_data;
-
-    BitField<29, 3, SubmissionMode> mode;
-};
-static_assert(std::is_standard_layout_v<CommandHeader>, "CommandHeader is not standard layout");
-static_assert(sizeof(CommandHeader) == sizeof(u32), "CommandHeader has incorrect size!");
-
-} // namespace Tegra

src/video_core/dma_pusher.cpp

@@ -0,0 +1,123 @@
+// Copyright 2018 yuzu Emulator Project
+// Licensed under GPLv2 or any later version
+// Refer to the license.txt file included.
+
+#include "common/microprofile.h"
+#include "core/core.h"
+#include "core/memory.h"
+#include "video_core/dma_pusher.h"
+#include "video_core/engines/maxwell_3d.h"
+#include "video_core/gpu.h"
+
+namespace Tegra {
+
+DmaPusher::DmaPusher(GPU& gpu) : gpu(gpu) {}
+
+DmaPusher::~DmaPusher() = default;
+
+MICROPROFILE_DEFINE(DispatchCalls, "GPU", "Execute command buffer", MP_RGB(128, 128, 192));
+
+void DmaPusher::DispatchCalls() {
+    MICROPROFILE_SCOPE(DispatchCalls);
+
+    // On entering GPU code, assume all memory may be touched by the ARM core.
+    gpu.Maxwell3D().dirty_flags.OnMemoryWrite();
+
+    dma_pushbuffer_subindex = 0;
+
+    while (Core::System::GetInstance().IsPoweredOn()) {
+        if (!Step()) {
+            break;
+        }
+    }
+}
+
+bool DmaPusher::Step() {
+    if (dma_get != dma_put) {
+        // Push buffer non-empty, read a word
+        const CommandHeader command_header{
+            Memory::Read32(*gpu.MemoryManager().GpuToCpuAddress(dma_get))};
+
+        dma_get += sizeof(u32);
+
+        if (!non_main) {
+            dma_mget = dma_get;
+        }
+
+        // now, see if we're in the middle of a command
+        if (dma_state.length_pending) {
+            // Second word of long non-inc methods command - method count
+            dma_state.length_pending = 0;
+            dma_state.method_count = command_header.method_count_;
+        } else if (dma_state.method_count) {
+            // Data word of methods command
+            CallMethod(command_header.argument);
+
+            if (!dma_state.non_incrementing) {
+                dma_state.method++;
+            }
+
+            if (dma_increment_once) {
+                dma_state.non_incrementing = true;
+            }
+
+            dma_state.method_count--;
+        } else {
+            // No command active - this is the first word of a new one
+            switch (command_header.mode) {
+            case SubmissionMode::Increasing:
+                SetState(command_header);
+                dma_state.non_incrementing = false;
+                dma_increment_once = false;
+                break;
+            case SubmissionMode::NonIncreasing:
+                SetState(command_header);
+                dma_state.non_incrementing = true;
+                dma_increment_once = false;
+                break;
+            case SubmissionMode::Inline:
+                dma_state.method = command_header.method;
+                dma_state.subchannel = command_header.subchannel;
+                CallMethod(command_header.arg_count);
+                dma_state.non_incrementing = true;
+                dma_increment_once = false;
+                break;
+            case SubmissionMode::IncreaseOnce:
+                SetState(command_header);
+                dma_state.non_incrementing = false;
+                dma_increment_once = true;
+                break;
+            }
+        }
+    } else if (ib_enable && !dma_pushbuffer.empty()) {
+        // Current pushbuffer empty, but we have more IB entries to read
+        const CommandList& command_list{dma_pushbuffer.front()};
+        const CommandListHeader& command_list_header{command_list[dma_pushbuffer_subindex++]};
+        dma_get = command_list_header.addr;
+        dma_put = dma_get + command_list_header.size * sizeof(u32);
+        non_main = command_list_header.is_non_main;
+
+        if (dma_pushbuffer_subindex >= command_list.size()) {
+            // We've gone through the current list, remove it from the queue
+            dma_pushbuffer.pop();
+            dma_pushbuffer_subindex = 0;
+        }
+    } else {
+        // Otherwise, pushbuffer empty and IB empty or nonexistent - nothing to do
+        return {};
+    }
+
+    return true;
+}
+
+void DmaPusher::SetState(const CommandHeader& command_header) {
+    dma_state.method = command_header.method;
+    dma_state.subchannel = command_header.subchannel;
+    dma_state.method_count = command_header.method_count;
+}
+
+void DmaPusher::CallMethod(u32 argument) const {
+    gpu.CallMethod({dma_state.method, argument, dma_state.subchannel, dma_state.method_count});
+}
+
+} // namespace Tegra

src/video_core/dma_pusher.h

@@ -0,0 +1,99 @@
+// Copyright 2018 yuzu Emulator Project
+// Licensed under GPLv2 or any later version
+// Refer to the license.txt file included.
+
+#pragma once
+
+#include <vector>
+#include <queue>
+
+#include "common/bit_field.h"
+#include "common/common_types.h"
+#include "video_core/memory_manager.h"
+
+namespace Tegra {
+
+enum class SubmissionMode : u32 {
+    IncreasingOld = 0,
+    Increasing = 1,
+    NonIncreasingOld = 2,
+    NonIncreasing = 3,
+    Inline = 4,
+    IncreaseOnce = 5
+};
+
+struct CommandListHeader {
+    union {
+        u64 raw;
+        BitField<0, 40, GPUVAddr> addr;
+        BitField<41, 1, u64> is_non_main;
+        BitField<42, 21, u64> size;
+    };
+};
+static_assert(sizeof(CommandListHeader) == sizeof(u64), "CommandListHeader is incorrect size");
+
+union CommandHeader {
+    u32 argument;
+    BitField<0, 13, u32> method;
+    BitField<0, 24, u32> method_count_;
+    BitField<13, 3, u32> subchannel;
+    BitField<16, 13, u32> arg_count;
+    BitField<16, 13, u32> method_count;
+    BitField<29, 3, SubmissionMode> mode;
+};
+static_assert(std::is_standard_layout_v<CommandHeader>, "CommandHeader is not standard layout");
+static_assert(sizeof(CommandHeader) == sizeof(u32), "CommandHeader has incorrect size!");
+
+class GPU;
+
+using CommandList = std::vector<Tegra::CommandListHeader>;
+
+/**
+ * The DmaPusher class implements DMA submission to FIFOs, providing an area of memory that the
+ * emulated app fills with commands and tells PFIFO to process. The pushbuffers are then assembled
+ * into a "command stream" consisting of 32-bit words that make up "commands".
+ * See https://envytools.readthedocs.io/en/latest/hw/fifo/dma-pusher.html#fifo-dma-pusher for
+ * details on this implementation.
+ */
+class DmaPusher {
+public:
+    explicit DmaPusher(GPU& gpu);
+    ~DmaPusher();
+
+    void Push(CommandList&& entries) {
+        dma_pushbuffer.push(std::move(entries));
+    }
+
+    void DispatchCalls();
+
+private:
+    bool Step();
+
+    void SetState(const CommandHeader& command_header);
+
+    void CallMethod(u32 argument) const;
+
+    GPU& gpu;
+
+    std::queue<CommandList> dma_pushbuffer; ///< Queue of command lists to be processed
+    std::size_t dma_pushbuffer_subindex{};  ///< Index within a command list within the pushbuffer
+
+    struct DmaState {
+        u32 method;            ///< Current method
+        u32 subchannel;        ///< Current subchannel
+        u32 method_count;      ///< Current method count
+        u32 length_pending;    ///< Large NI command length pending
+        bool non_incrementing; ///< Current command’s NI flag
+    };
+
+    DmaState dma_state{};
+    bool dma_increment_once{};
+
+    GPUVAddr dma_put{};   ///< pushbuffer current end address
+    GPUVAddr dma_get{};   ///< pushbuffer current read address
+    GPUVAddr dma_mget{};  ///< main pushbuffer last read address
+    bool ib_enable{true}; ///< IB mode enabled
+    bool non_main{};      ///< non-main pushbuffer active
+};
+
+} // namespace Tegra

src/video_core/engines/fermi_2d.cpp

@@ -14,13 +14,13 @@ namespace Tegra::Engines {
 Fermi2D::Fermi2D(VideoCore::RasterizerInterface& rasterizer, MemoryManager& memory_manager)
     : memory_manager(memory_manager), rasterizer{rasterizer} {}
 
-void Fermi2D::WriteReg(u32 method, u32 value) {
-    ASSERT_MSG(method < Regs::NUM_REGS,
+void Fermi2D::CallMethod(const GPU::MethodCall& method_call) {
+    ASSERT_MSG(method_call.method < Regs::NUM_REGS,
                "Invalid Fermi2D register, increase the size of the Regs structure");
 
-    regs.reg_array[method] = value;
+    regs.reg_array[method_call.method] = method_call.argument;
 
-    switch (method) {
+    switch (method_call.method) {
     case FERMI2D_REG_INDEX(trigger): {
         HandleSurfaceCopy();
         break;
@@ -73,13 +73,13 @@ void Fermi2D::HandleSurfaceCopy() {
             Texture::CopySwizzledData(regs.src.width, regs.src.height, regs.src.depth,
                                       src_bytes_per_pixel, dst_bytes_per_pixel, src_buffer,
                                       dst_buffer, true, regs.src.BlockHeight(),
-                                      regs.src.BlockDepth());
+                                      regs.src.BlockDepth(), 0);
         } else {
             // If the input is linear and the output is tiled, swizzle the input and copy it over.
             Texture::CopySwizzledData(regs.src.width, regs.src.height, regs.src.depth,
                                       src_bytes_per_pixel, dst_bytes_per_pixel, dst_buffer,
                                       src_buffer, false, regs.dst.BlockHeight(),
-                                      regs.dst.BlockDepth());
+                                      regs.dst.BlockDepth(), 0);
         }
     }
 }

src/video_core/engines/fermi_2d.h

@@ -27,7 +27,7 @@ public:
     ~Fermi2D() = default;
 
     /// Write the value to the register identified by method.
-    void WriteReg(u32 method, u32 value);
+    void CallMethod(const GPU::MethodCall& method_call);
 
     struct Regs {
         static constexpr std::size_t NUM_REGS = 0x258;

src/video_core/engines/kepler_memory.cpp

@@ -17,19 +17,19 @@ KeplerMemory::KeplerMemory(VideoCore::RasterizerInterface& rasterizer,
 
 KeplerMemory::~KeplerMemory() = default;
 
-void KeplerMemory::WriteReg(u32 method, u32 value) {
-    ASSERT_MSG(method < Regs::NUM_REGS,
+void KeplerMemory::CallMethod(const GPU::MethodCall& method_call) {
+    ASSERT_MSG(method_call.method < Regs::NUM_REGS,
                "Invalid KeplerMemory register, increase the size of the Regs structure");
 
-    regs.reg_array[method] = value;
+    regs.reg_array[method_call.method] = method_call.argument;
 
-    switch (method) {
+    switch (method_call.method) {
     case KEPLERMEMORY_REG_INDEX(exec): {
         state.write_offset = 0;
         break;
     }
     case KEPLERMEMORY_REG_INDEX(data): {
-        ProcessData(value);
+        ProcessData(method_call.argument);
         break;
     }
     }

src/video_core/engines/kepler_memory.h

@@ -9,6 +9,7 @@
 #include "common/bit_field.h"
 #include "common/common_funcs.h"
 #include "common/common_types.h"
+#include "video_core/gpu.h"
 #include "video_core/memory_manager.h"
 
 namespace VideoCore {
@@ -26,7 +27,7 @@ public:
     ~KeplerMemory();
 
     /// Write the value to the register identified by method.
-    void WriteReg(u32 method, u32 value);
+    void CallMethod(const GPU::MethodCall& method_call);
 
     struct Regs {
         static constexpr size_t NUM_REGS = 0x7F;

src/video_core/engines/maxwell_3d.cpp

@@ -97,71 +97,74 @@ void Maxwell3D::CallMacroMethod(u32 method, std::vector<u32> parameters) {
     macro_interpreter.Execute(search->second, std::move(parameters));
 }
 
-void Maxwell3D::WriteReg(u32 method, u32 value, u32 remaining_params) {
+void Maxwell3D::CallMethod(const GPU::MethodCall& method_call) {
     auto debug_context = Core::System::GetInstance().GetGPUDebugContext();
 
     // It is an error to write to a register other than the current macro's ARG register before it
     // has finished execution.
     if (executing_macro != 0) {
-        ASSERT(method == executing_macro + 1);
+        ASSERT(method_call.method == executing_macro + 1);
     }
 
     // Methods after 0xE00 are special, they're actually triggers for some microcode that was
     // uploaded to the GPU during initialization.
-    if (method >= MacroRegistersStart) {
+    if (method_call.method >= MacroRegistersStart) {
         // We're trying to execute a macro
         if (executing_macro == 0) {
             // A macro call must begin by writing the macro method's register, not its argument.
-            ASSERT_MSG((method % 2) == 0,
+            ASSERT_MSG((method_call.method % 2) == 0,
                        "Can't start macro execution by writing to the ARGS register");
-            executing_macro = method;
+            executing_macro = method_call.method;
         }
 
-        macro_params.push_back(value);
+        macro_params.push_back(method_call.argument);
 
         // Call the macro when there are no more parameters in the command buffer
-        if (remaining_params == 0) {
+        if (method_call.IsLastCall()) {
             CallMacroMethod(executing_macro, std::move(macro_params));
         }
         return;
     }
 
-    ASSERT_MSG(method < Regs::NUM_REGS,
+    ASSERT_MSG(method_call.method < Regs::NUM_REGS,
                "Invalid Maxwell3D register, increase the size of the Regs structure");
 
     if (debug_context) {
         debug_context->OnEvent(Tegra::DebugContext::Event::MaxwellCommandLoaded, nullptr);
     }
 
-    if (regs.reg_array[method] != value) {
-        regs.reg_array[method] = value;
+    if (regs.reg_array[method_call.method] != method_call.argument) {
+        regs.reg_array[method_call.method] = method_call.argument;
         // Vertex format
-        if (method >= MAXWELL3D_REG_INDEX(vertex_attrib_format) &&
-            method < MAXWELL3D_REG_INDEX(vertex_attrib_format) + regs.vertex_attrib_format.size()) {
+        if (method_call.method >= MAXWELL3D_REG_INDEX(vertex_attrib_format) &&
+            method_call.method <
+                MAXWELL3D_REG_INDEX(vertex_attrib_format) + regs.vertex_attrib_format.size()) {
             dirty_flags.vertex_attrib_format = true;
         }
 
         // Vertex buffer
-        if (method >= MAXWELL3D_REG_INDEX(vertex_array) &&
-            method < MAXWELL3D_REG_INDEX(vertex_array) + 4 * 32) {
-            dirty_flags.vertex_array |= 1u << ((method - MAXWELL3D_REG_INDEX(vertex_array)) >> 2);
-        } else if (method >= MAXWELL3D_REG_INDEX(vertex_array_limit) &&
-                   method < MAXWELL3D_REG_INDEX(vertex_array_limit) + 2 * 32) {
+        if (method_call.method >= MAXWELL3D_REG_INDEX(vertex_array) &&
+            method_call.method < MAXWELL3D_REG_INDEX(vertex_array) + 4 * 32) {
             dirty_flags.vertex_array |=
-                1u << ((method - MAXWELL3D_REG_INDEX(vertex_array_limit)) >> 1);
-        } else if (method >= MAXWELL3D_REG_INDEX(instanced_arrays) &&
-                   method < MAXWELL3D_REG_INDEX(instanced_arrays) + 32) {
-            dirty_flags.vertex_array |= 1u << (method - MAXWELL3D_REG_INDEX(instanced_arrays));
+                1u << ((method_call.method - MAXWELL3D_REG_INDEX(vertex_array)) >> 2);
+        } else if (method_call.method >= MAXWELL3D_REG_INDEX(vertex_array_limit) &&
+                   method_call.method < MAXWELL3D_REG_INDEX(vertex_array_limit) + 2 * 32) {
+            dirty_flags.vertex_array |=
+                1u << ((method_call.method - MAXWELL3D_REG_INDEX(vertex_array_limit)) >> 1);
+        } else if (method_call.method >= MAXWELL3D_REG_INDEX(instanced_arrays) &&
+                   method_call.method < MAXWELL3D_REG_INDEX(instanced_arrays) + 32) {
+            dirty_flags.vertex_array |=
+                1u << (method_call.method - MAXWELL3D_REG_INDEX(instanced_arrays));
         }
     }
 
-    switch (method) {
+    switch (method_call.method) {
     case MAXWELL3D_REG_INDEX(macros.data): {
-        ProcessMacroUpload(value);
+        ProcessMacroUpload(method_call.argument);
         break;
     }
     case MAXWELL3D_REG_INDEX(macros.bind): {
-        ProcessMacroBind(value);
+        ProcessMacroBind(method_call.argument);
         break;
     }
     case MAXWELL3D_REG_INDEX(const_buffer.cb_data[0]):
@@ -180,7 +183,7 @@ void Maxwell3D::WriteReg(u32 method, u32 value, u32 remaining_params) {
     case MAXWELL3D_REG_INDEX(const_buffer.cb_data[13]):
     case MAXWELL3D_REG_INDEX(const_buffer.cb_data[14]):
     case MAXWELL3D_REG_INDEX(const_buffer.cb_data[15]): {
-        ProcessCBData(value);
+        ProcessCBData(method_call.argument);
         break;
     }
     case MAXWELL3D_REG_INDEX(cb_bind[0].raw_config): {

src/video_core/engines/maxwell_3d.h

@@ -744,7 +744,20 @@ public:
 
                 u32 vb_element_base;
 
-                INSERT_PADDING_WORDS(0x38);
+                INSERT_PADDING_WORDS(0x36);
+
+                union {
+                    BitField<0, 1, u32> c0;
+                    BitField<1, 1, u32> c1;
+                    BitField<2, 1, u32> c2;
+                    BitField<3, 1, u32> c3;
+                    BitField<4, 1, u32> c4;
+                    BitField<5, 1, u32> c5;
+                    BitField<6, 1, u32> c6;
+                    BitField<7, 1, u32> c7;
+                } clip_distance_enabled;
+
+                INSERT_PADDING_WORDS(0x1);
 
                 float point_size;
 
@@ -902,8 +915,15 @@ public:
 
                 u32 viewport_transform_enabled;
 
-                INSERT_PADDING_WORDS(0x25);
+                INSERT_PADDING_WORDS(0x3);
 
+                union {
+                    BitField<0, 1, u32> depth_range_0_1;
+                    BitField<3, 1, u32> depth_clamp_near;
+                    BitField<4, 1, u32> depth_clamp_far;
+                } view_volume_clip_control;
+
+                INSERT_PADDING_WORDS(0x21);
                 struct {
                     u32 enable;
                     LogicOperation operation;
@@ -1080,7 +1100,7 @@ public:
     u32 GetRegisterValue(u32 method) const;
 
     /// Write the value to the register identified by method.
-    void WriteReg(u32 method, u32 value, u32 remaining_params);
+    void CallMethod(const GPU::MethodCall& method_call);
 
     /// Returns a list of enabled textures for the specified shader stage.
     std::vector<Texture::FullTextureInfo> GetStageTextures(Regs::ShaderStage stage) const;
@@ -1201,6 +1221,7 @@ ASSERT_REG_POSITION(stencil_front_mask, 0x4E7);
 ASSERT_REG_POSITION(frag_color_clamp, 0x4EA);
 ASSERT_REG_POSITION(screen_y_control, 0x4EB);
 ASSERT_REG_POSITION(vb_element_base, 0x50D);
+ASSERT_REG_POSITION(clip_distance_enabled, 0x544);
 ASSERT_REG_POSITION(point_size, 0x546);
 ASSERT_REG_POSITION(zeta_enable, 0x54E);
 ASSERT_REG_POSITION(multisample_control, 0x54F);
@@ -1224,6 +1245,7 @@ ASSERT_REG_POSITION(instanced_arrays, 0x620);
 ASSERT_REG_POSITION(cull, 0x646);
 ASSERT_REG_POSITION(pixel_center_integer, 0x649);
 ASSERT_REG_POSITION(viewport_transform_enabled, 0x64B);
+ASSERT_REG_POSITION(view_volume_clip_control, 0x64F);
 ASSERT_REG_POSITION(logic_op, 0x671);
 ASSERT_REG_POSITION(clear_buffers, 0x674);
 ASSERT_REG_POSITION(color_mask, 0x680);

src/video_core/engines/maxwell_compute.cpp

@@ -8,13 +8,13 @@
 
 namespace Tegra::Engines {
 
-void MaxwellCompute::WriteReg(u32 method, u32 value) {
-    ASSERT_MSG(method < Regs::NUM_REGS,
+void MaxwellCompute::CallMethod(const GPU::MethodCall& method_call) {
+    ASSERT_MSG(method_call.method < Regs::NUM_REGS,
                "Invalid MaxwellCompute register, increase the size of the Regs structure");
 
-    regs.reg_array[method] = value;
+    regs.reg_array[method_call.method] = method_call.argument;
 
-    switch (method) {
+    switch (method_call.method) {
     case MAXWELL_COMPUTE_REG_INDEX(compute): {
         LOG_CRITICAL(HW_GPU, "Compute shaders are not implemented");
         UNREACHABLE();

src/video_core/engines/maxwell_compute.h

@@ -9,6 +9,7 @@
 #include "common/bit_field.h"
 #include "common/common_funcs.h"
 #include "common/common_types.h"
+#include "video_core/gpu.h"
 
 namespace Tegra::Engines {
 
@@ -42,7 +43,7 @@ public:
                   "MaxwellCompute Regs has wrong size");
 
     /// Write the value to the register identified by method.
-    void WriteReg(u32 method, u32 value);
+    void CallMethod(const GPU::MethodCall& method_call);
 };
 
 #define ASSERT_REG_POSITION(field_name, position)                                                  \

src/video_core/engines/maxwell_dma.cpp

@@ -14,16 +14,16 @@ namespace Tegra::Engines {
 MaxwellDMA::MaxwellDMA(VideoCore::RasterizerInterface& rasterizer, MemoryManager& memory_manager)
     : memory_manager(memory_manager), rasterizer{rasterizer} {}
 
-void MaxwellDMA::WriteReg(u32 method, u32 value) {
-    ASSERT_MSG(method < Regs::NUM_REGS,
+void MaxwellDMA::CallMethod(const GPU::MethodCall& method_call) {
+    ASSERT_MSG(method_call.method < Regs::NUM_REGS,
                "Invalid MaxwellDMA register, increase the size of the Regs structure");
 
-    regs.reg_array[method] = value;
+    regs.reg_array[method_call.method] = method_call.argument;
 
 #define MAXWELLDMA_REG_INDEX(field_name)                                                           \
     (offsetof(Tegra::Engines::MaxwellDMA::Regs, field_name) / sizeof(u32))
 
-    switch (method) {
+    switch (method_call.method) {
     case MAXWELLDMA_REG_INDEX(exec): {
         HandleCopy();
         break;

src/video_core/engines/maxwell_dma.h

@@ -24,7 +24,7 @@ public:
     ~MaxwellDMA() = default;
 
     /// Write the value to the register identified by method.
-    void WriteReg(u32 method, u32 value);
+    void CallMethod(const GPU::MethodCall& method_call);
 
     struct Regs {
         static constexpr std::size_t NUM_REGS = 0x1D6;

src/video_core/gpu.cpp

@@ -26,6 +26,7 @@ u32 FramebufferConfig::BytesPerPixel(PixelFormat format) {
 
 GPU::GPU(VideoCore::RasterizerInterface& rasterizer) {
     memory_manager = std::make_unique<Tegra::MemoryManager>();
+    dma_pusher = std::make_unique<Tegra::DmaPusher>(*this);
     maxwell_3d = std::make_unique<Engines::Maxwell3D>(rasterizer, *memory_manager);
     fermi_2d = std::make_unique<Engines::Fermi2D>(rasterizer, *memory_manager);
     maxwell_compute = std::make_unique<Engines::MaxwellCompute>();
@@ -51,6 +52,14 @@ const MemoryManager& GPU::MemoryManager() const {
     return *memory_manager;
 }
 
+DmaPusher& GPU::DmaPusher() {
+    return *dma_pusher;
+}
+
+const DmaPusher& GPU::DmaPusher() const {
+    return *dma_pusher;
+}
+
 u32 RenderTargetBytesPerPixel(RenderTargetFormat format) {
     ASSERT(format != RenderTargetFormat::NONE);
 
@@ -113,4 +122,46 @@ u32 DepthFormatBytesPerPixel(DepthFormat format) {
     }
 }
 
+enum class BufferMethods {
+    BindObject = 0,
+    CountBufferMethods = 0x40,
+};
+
+void GPU::CallMethod(const MethodCall& method_call) {
+    LOG_TRACE(HW_GPU, "Processing method {:08X} on subchannel {}", method_call.method,
+              method_call.subchannel);
+
+    ASSERT(method_call.subchannel < bound_engines.size());
+
+    if (method_call.method == static_cast<u32>(BufferMethods::BindObject)) {
+        // Bind the current subchannel to the desired engine id.
+        LOG_DEBUG(HW_GPU, "Binding subchannel {} to engine {}", method_call.subchannel,
+                  method_call.argument);
+        bound_engines[method_call.subchannel] = static_cast<EngineID>(method_call.argument);
+        return;
+    }
+
+    const EngineID engine = bound_engines[method_call.subchannel];
+
+    switch (engine) {
+    case EngineID::FERMI_TWOD_A:
+        fermi_2d->CallMethod(method_call);
+        break;
+    case EngineID::MAXWELL_B:
+        maxwell_3d->CallMethod(method_call);
+        break;
+    case EngineID::MAXWELL_COMPUTE_B:
+        maxwell_compute->CallMethod(method_call);
+        break;
+    case EngineID::MAXWELL_DMA_COPY_A:
+        maxwell_dma->CallMethod(method_call);
+        break;
+    case EngineID::KEPLER_INLINE_TO_MEMORY_B:
+        kepler_memory->CallMethod(method_call);
+        break;
+    default:
+        UNIMPLEMENTED_MSG("Unimplemented engine");
+    }
+}
+
 } // namespace Tegra

src/video_core/gpu.h

@@ -9,6 +9,7 @@
 #include <vector>
 #include "common/common_types.h"
 #include "core/hle/service/nvflinger/buffer_queue.h"
+#include "video_core/dma_pusher.h"
 #include "video_core/memory_manager.h"
 
 namespace VideoCore {
@@ -119,8 +120,23 @@ public:
     explicit GPU(VideoCore::RasterizerInterface& rasterizer);
     ~GPU();
 
-    /// Processes a command list stored at the specified address in GPU memory.
-    void ProcessCommandLists(const std::vector<CommandListHeader>& commands);
+    struct MethodCall {
+        u32 method{};
+        u32 argument{};
+        u32 subchannel{};
+        u32 method_count{};
+
+        bool IsLastCall() const {
+            return method_count <= 1;
+        }
+
+        MethodCall(u32 method, u32 argument, u32 subchannel = 0, u32 method_count = 0)
+            : method(method), argument(argument), subchannel(subchannel),
+              method_count(method_count) {}
+    };
+
+    /// Calls a GPU method.
+    void CallMethod(const MethodCall& method_call);
 
     /// Returns a reference to the Maxwell3D GPU engine.
     Engines::Maxwell3D& Maxwell3D();
@@ -134,7 +150,14 @@ public:
     /// Returns a const reference to the GPU memory manager.
     const Tegra::MemoryManager& MemoryManager() const;
 
+    /// Returns a reference to the GPU DMA pusher.
+    Tegra::DmaPusher& DmaPusher();
+
+    /// Returns a const reference to the GPU DMA pusher.
+    const Tegra::DmaPusher& DmaPusher() const;
+
 private:
+    std::unique_ptr<Tegra::DmaPusher> dma_pusher;
     std::unique_ptr<Tegra::MemoryManager> memory_manager;
 
     /// Mapping of command subchannels to their bound engine ids.

src/video_core/macro_interpreter.cpp

@@ -250,7 +250,7 @@ void MacroInterpreter::SetMethodAddress(u32 address) {
 }
 
 void MacroInterpreter::Send(u32 value) {
-    maxwell3d.WriteReg(method_address.address, value, 0);
+    maxwell3d.CallMethod({method_address.address, value});
     // Increment the method address by the method increment.
     method_address.address.Assign(method_address.address.Value() +
                                   method_address.increment.Value());

src/video_core/morton.cpp

@@ -16,12 +16,12 @@ namespace VideoCore {
 using Surface::GetBytesPerPixel;
 using Surface::PixelFormat;
 
-using MortonCopyFn = void (*)(u32, u32, u32, u32, u32, u8*, std::size_t, VAddr);
+using MortonCopyFn = void (*)(u32, u32, u32, u32, u32, u32, u8*, std::size_t, VAddr);
 using ConversionArray = std::array<MortonCopyFn, Surface::MaxPixelFormat>;
 
 template <bool morton_to_linear, PixelFormat format>
 static void MortonCopy(u32 stride, u32 block_height, u32 height, u32 block_depth, u32 depth,
-                       u8* buffer, std::size_t buffer_size, VAddr addr) {
+                       u32 tile_width_spacing, u8* buffer, std::size_t buffer_size, VAddr addr) {
     constexpr u32 bytes_per_pixel = GetBytesPerPixel(format);
 
     // With the BCn formats (DXT and DXN), each 4x4 tile is swizzled instead of just individual
@@ -31,12 +31,13 @@ static void MortonCopy(u32 stride, u32 block_height, u32 height, u32 block_depth
 
     if constexpr (morton_to_linear) {
         Tegra::Texture::UnswizzleTexture(buffer, addr, tile_size_x, tile_size_y, bytes_per_pixel,
-                                         stride, height, depth, block_height, block_depth);
+                                         stride, height, depth, block_height, block_depth,
+                                         tile_width_spacing);
     } else {
-        Tegra::Texture::CopySwizzledData((stride + tile_size_x - 1) / tile_size_x,
-                                         (height + tile_size_y - 1) / tile_size_y, depth,
-                                         bytes_per_pixel, bytes_per_pixel, Memory::GetPointer(addr),
-                                         buffer, false, block_height, block_depth);
+        Tegra::Texture::CopySwizzledData(
+            (stride + tile_size_x - 1) / tile_size_x, (height + tile_size_y - 1) / tile_size_y,
+            depth, bytes_per_pixel, bytes_per_pixel, Memory::GetPointer(addr), buffer, false,
+            block_height, block_depth, tile_width_spacing);
     }
 }
 
@@ -326,11 +327,11 @@ static u32 GetMortonOffset128(u32 x, u32 y, u32 bytes_per_pixel) {
 }
 
 void MortonSwizzle(MortonSwizzleMode mode, Surface::PixelFormat format, u32 stride,
-                   u32 block_height, u32 height, u32 block_depth, u32 depth, u8* buffer,
-                   std::size_t buffer_size, VAddr addr) {
+                   u32 block_height, u32 height, u32 block_depth, u32 depth, u32 tile_width_spacing,
+                   u8* buffer, std::size_t buffer_size, VAddr addr) {
 
-    GetSwizzleFunction(mode, format)(stride, block_height, height, block_depth, depth, buffer,
-                                     buffer_size, addr);
+    GetSwizzleFunction(mode, format)(stride, block_height, height, block_depth, depth,
+                                     tile_width_spacing, buffer, buffer_size, addr);
 }
 
 void MortonCopyPixels128(u32 width, u32 height, u32 bytes_per_pixel, u32 linear_bytes_per_pixel,
@@ -351,4 +352,4 @@ void MortonCopyPixels128(u32 width, u32 height, u32 bytes_per_pixel, u32 linear_
     }
 }
 
-} // namespace VideoCore
+} // namespace VideoCore

src/video_core/morton.h

@@ -12,10 +12,10 @@ namespace VideoCore {
 enum class MortonSwizzleMode { MortonToLinear, LinearToMorton };
 
 void MortonSwizzle(MortonSwizzleMode mode, VideoCore::Surface::PixelFormat format, u32 stride,
-                   u32 block_height, u32 height, u32 block_depth, u32 depth, u8* buffer,
-                   std::size_t buffer_size, VAddr addr);
+                   u32 block_height, u32 height, u32 block_depth, u32 depth, u32 tile_width_spacing,
+                   u8* buffer, std::size_t buffer_size, VAddr addr);
 
 void MortonCopyPixels128(u32 width, u32 height, u32 bytes_per_pixel, u32 linear_bytes_per_pixel,
                          u8* morton_data, u8* linear_data, bool morton_to_linear);
 
-} // namespace VideoCore
+} // namespace VideoCore

src/video_core/renderer_opengl/gl_rasterizer.cpp

@@ -113,10 +113,24 @@ RasterizerOpenGL::RasterizerOpenGL(Core::Frontend::EmuWindow& window, ScreenInfo
     glGetIntegerv(GL_UNIFORM_BUFFER_OFFSET_ALIGNMENT, &uniform_buffer_alignment);
 
     LOG_CRITICAL(Render_OpenGL, "Sync fixed function OpenGL state here!");
+    CheckExtensions();
 }
 
 RasterizerOpenGL::~RasterizerOpenGL() {}
 
+void RasterizerOpenGL::CheckExtensions() {
+    if (!GLAD_GL_ARB_texture_filter_anisotropic && !GLAD_GL_EXT_texture_filter_anisotropic) {
+        LOG_WARNING(
+            Render_OpenGL,
+            "Anisotropic filter is not supported! This can cause graphical issues in some games.");
+    }
+    if (!GLAD_GL_ARB_buffer_storage) {
+        LOG_WARNING(
+            Render_OpenGL,
+            "Buffer storage control is not supported! This can cause performance degradation.");
+    }
+}
+
 void RasterizerOpenGL::SetupVertexFormat() {
     auto& gpu = Core::System::GetInstance().GPU().Maxwell3D();
     const auto& regs = gpu.regs;
@@ -628,6 +642,7 @@ void RasterizerOpenGL::DrawArrays() {
     SyncCullMode();
     SyncPrimitiveRestart();
     SyncScissorTest(state);
+    SyncClipEnabled();
     // Alpha Testing is synced on shaders.
     SyncTransformFeedback();
     SyncPointState();
@@ -992,25 +1007,28 @@ void RasterizerOpenGL::SyncViewport(OpenGLState& current_state) {
     for (std::size_t i = 0; i < viewport_count; i++) {
         auto& viewport = current_state.viewports[i];
         const auto& src = regs.viewports[i];
-        if (regs.viewport_transform_enabled) {
-            const MathUtil::Rectangle<s32> viewport_rect{regs.viewport_transform[i].GetRect()};
-            viewport.x = viewport_rect.left;
-            viewport.y = viewport_rect.bottom;
-            viewport.width = viewport_rect.GetWidth();
-            viewport.height = viewport_rect.GetHeight();
-        } else {
-            viewport.x = src.x;
-            viewport.y = src.y;
-            viewport.width = src.width;
-            viewport.height = src.height;
-        }
+        const MathUtil::Rectangle<s32> viewport_rect{regs.viewport_transform[i].GetRect()};
+        viewport.x = viewport_rect.left;
+        viewport.y = viewport_rect.bottom;
+        viewport.width = viewport_rect.GetWidth();
+        viewport.height = viewport_rect.GetHeight();
         viewport.depth_range_far = regs.viewports[i].depth_range_far;
         viewport.depth_range_near = regs.viewports[i].depth_range_near;
     }
+    state.depth_clamp.far_plane = regs.view_volume_clip_control.depth_clamp_far != 0;
+    state.depth_clamp.near_plane = regs.view_volume_clip_control.depth_clamp_near != 0;
 }
 
 void RasterizerOpenGL::SyncClipEnabled() {
-    UNREACHABLE();
+    const auto& regs = Core::System::GetInstance().GPU().Maxwell3D().regs;
+    state.clip_distance[0] = regs.clip_distance_enabled.c0 != 0;
+    state.clip_distance[1] = regs.clip_distance_enabled.c1 != 0;
+    state.clip_distance[2] = regs.clip_distance_enabled.c2 != 0;
+    state.clip_distance[3] = regs.clip_distance_enabled.c3 != 0;
+    state.clip_distance[4] = regs.clip_distance_enabled.c4 != 0;
+    state.clip_distance[5] = regs.clip_distance_enabled.c5 != 0;
+    state.clip_distance[6] = regs.clip_distance_enabled.c6 != 0;
+    state.clip_distance[7] = regs.clip_distance_enabled.c7 != 0;
 }
 
 void RasterizerOpenGL::SyncClipCoef() {

src/video_core/renderer_opengl/gl_rasterizer.h

@@ -189,6 +189,10 @@ private:
     /// Check asserts for alpha testing.
     void CheckAlphaTests();
 
+    /// Check for extension that are not strictly required
+    /// but are needed for correct emulation
+    void CheckExtensions();
+
     bool has_ARB_direct_state_access = false;
     bool has_ARB_multi_bind = false;
 

src/video_core/renderer_opengl/gl_rasterizer_cache.cpp

@@ -97,6 +97,7 @@ std::size_t SurfaceParams::InnerMemorySize(bool force_gl, bool layer_only,
     params.block_width = params.is_tiled ? config.tic.BlockWidth() : 0,
     params.block_height = params.is_tiled ? config.tic.BlockHeight() : 0,
     params.block_depth = params.is_tiled ? config.tic.BlockDepth() : 0,
+    params.tile_width_spacing = params.is_tiled ? (1 << config.tic.tile_width_spacing.Value()) : 1;
     params.srgb_conversion = config.tic.IsSrgbConversionEnabled();
     params.pixel_format = PixelFormatFromTextureFormat(config.tic.format, config.tic.r_type.Value(),
                                                        params.srgb_conversion);
@@ -162,6 +163,7 @@ std::size_t SurfaceParams::InnerMemorySize(bool force_gl, bool layer_only,
     params.block_width = 1 << config.memory_layout.block_width;
     params.block_height = 1 << config.memory_layout.block_height;
     params.block_depth = 1 << config.memory_layout.block_depth;
+    params.tile_width_spacing = 1;
     params.pixel_format = PixelFormatFromRenderTargetFormat(config.format);
     params.srgb_conversion = config.format == Tegra::RenderTargetFormat::BGRA8_SRGB ||
                              config.format == Tegra::RenderTargetFormat::RGBA8_SRGB;
@@ -197,6 +199,7 @@ std::size_t SurfaceParams::InnerMemorySize(bool force_gl, bool layer_only,
     params.block_width = 1 << std::min(block_width, 5U);
     params.block_height = 1 << std::min(block_height, 5U);
     params.block_depth = 1 << std::min(block_depth, 5U);
+    params.tile_width_spacing = 1;
     params.pixel_format = PixelFormatFromDepthFormat(format);
     params.component_type = ComponentTypeFromDepthFormat(format);
     params.type = GetFormatType(params.pixel_format);
@@ -223,6 +226,7 @@ std::size_t SurfaceParams::InnerMemorySize(bool force_gl, bool layer_only,
     params.block_width = params.is_tiled ? std::min(config.BlockWidth(), 32U) : 0,
     params.block_height = params.is_tiled ? std::min(config.BlockHeight(), 32U) : 0,
     params.block_depth = params.is_tiled ? std::min(config.BlockDepth(), 32U) : 0,
+    params.tile_width_spacing = 1;
     params.pixel_format = PixelFormatFromRenderTargetFormat(config.format);
     params.srgb_conversion = config.format == Tegra::RenderTargetFormat::BGRA8_SRGB ||
                              config.format == Tegra::RenderTargetFormat::RGBA8_SRGB;
@@ -387,8 +391,8 @@ void SwizzleFunc(const MortonSwizzleMode& mode, const SurfaceParams& params,
         for (u32 i = 0; i < params.depth; i++) {
             MortonSwizzle(mode, params.pixel_format, params.MipWidth(mip_level),
                           params.MipBlockHeight(mip_level), params.MipHeight(mip_level),
-                          params.MipBlockDepth(mip_level), 1, gl_buffer.data() + offset_gl, gl_size,
-                          params.addr + offset);
+                          params.MipBlockDepth(mip_level), params.tile_width_spacing, 1,
+                          gl_buffer.data() + offset_gl, gl_size, params.addr + offset);
             offset += layer_size;
             offset_gl += gl_size;
         }
@@ -396,8 +400,8 @@ void SwizzleFunc(const MortonSwizzleMode& mode, const SurfaceParams& params,
         const u64 offset = params.GetMipmapLevelOffset(mip_level);
         MortonSwizzle(mode, params.pixel_format, params.MipWidth(mip_level),
                       params.MipBlockHeight(mip_level), params.MipHeight(mip_level),
-                      params.MipBlockDepth(mip_level), depth, gl_buffer.data(), gl_buffer.size(),
-                      params.addr + offset);
+                      params.MipBlockDepth(mip_level), depth, params.tile_width_spacing,
+                      gl_buffer.data(), gl_buffer.size(), params.addr + offset);
     }
 }
 

src/video_core/renderer_opengl/gl_rasterizer_cache.h

@@ -196,9 +196,15 @@ struct SurfaceParams {
 
     /// Checks if surfaces are compatible for caching
     bool IsCompatibleSurface(const SurfaceParams& other) const {
-        return std::tie(pixel_format, type, width, height, target, depth) ==
-               std::tie(other.pixel_format, other.type, other.width, other.height, other.target,
-                        other.depth);
+        if (std::tie(pixel_format, type, width, height, target, depth, is_tiled) ==
+            std::tie(other.pixel_format, other.type, other.width, other.height, other.target,
+                     other.depth, other.is_tiled)) {
+            if (!is_tiled)
+                return true;
+            return std::tie(block_height, block_depth, tile_width_spacing) ==
+                   std::tie(other.block_height, other.block_depth, other.tile_width_spacing);
+        }
+        return false;
     }
 
     /// Initializes parameters for caching, should be called after everything has been initialized
@@ -208,6 +214,7 @@ struct SurfaceParams {
     u32 block_width;
     u32 block_height;
     u32 block_depth;
+    u32 tile_width_spacing;
     PixelFormat pixel_format;
     ComponentType component_type;
     SurfaceType type;

src/video_core/renderer_opengl/gl_shader_decompiler.cpp

@@ -520,7 +520,7 @@ public:
         switch (attribute) {
         case Attribute::Index::ClipDistances0123:
         case Attribute::Index::ClipDistances4567: {
-            const u64 index = attribute == Attribute::Index::ClipDistances4567 ? 4 : 0 + elem;
+            const u64 index = (attribute == Attribute::Index::ClipDistances4567 ? 4 : 0) + elem;
             UNIMPLEMENTED_IF_MSG(
                 ((header.vtg.clip_distances >> index) & 1) == 0,
                 "Shader is setting gl_ClipDistance{} without enabling it in the header", index);

src/video_core/renderer_opengl/gl_state.cpp

@@ -92,7 +92,8 @@ OpenGLState::OpenGLState() {
 
     point.size = 1;
     fragment_color_clamp.enabled = false;
-
+    depth_clamp.far_plane = false;
+    depth_clamp.near_plane = false;
     polygon_offset.fill_enable = false;
     polygon_offset.line_enable = false;
     polygon_offset.point_enable = false;
@@ -147,7 +148,7 @@ void OpenGLState::ApplyCulling() const {
 }
 
 void OpenGLState::ApplyColorMask() const {
-    if (GLAD_GL_ARB_viewport_array && independant_blend.enabled) {
+    if (independant_blend.enabled) {
         for (size_t i = 0; i < Tegra::Engines::Maxwell3D::Regs::NumRenderTargets; i++) {
             const auto& updated = color_mask[i];
             const auto& current = cur_state.color_mask[i];
@@ -264,7 +265,7 @@ void OpenGLState::EmulateViewportWithScissor() {
 }
 
 void OpenGLState::ApplyViewport() const {
-    if (GLAD_GL_ARB_viewport_array && geometry_shaders.enabled) {
+    if (geometry_shaders.enabled) {
         for (GLuint i = 0; i < static_cast<GLuint>(Tegra::Engines::Maxwell3D::Regs::NumViewports);
              i++) {
             const auto& current = cur_state.viewports[i];
@@ -525,6 +526,21 @@ void OpenGLState::ApplyVertexBufferState() const {
     }
 }
 
+void OpenGLState::ApplyDepthClamp() const {
+    if (depth_clamp.far_plane == cur_state.depth_clamp.far_plane &&
+        depth_clamp.near_plane == cur_state.depth_clamp.near_plane) {
+        return;
+    }
+    if (depth_clamp.far_plane != depth_clamp.near_plane) {
+        UNIMPLEMENTED_MSG("Unimplemented Depth Clamp Separation!");
+    }
+    if (depth_clamp.far_plane || depth_clamp.near_plane) {
+        glEnable(GL_DEPTH_CLAMP);
+    } else {
+        glDisable(GL_DEPTH_CLAMP);
+    }
+}
+
 void OpenGLState::Apply() const {
     ApplyFramebufferState();
     ApplyVertexBufferState();
@@ -556,11 +572,9 @@ void OpenGLState::Apply() const {
     if (point.size != cur_state.point.size) {
         glPointSize(point.size);
     }
-    if (GLAD_GL_ARB_color_buffer_float) {
-        if (fragment_color_clamp.enabled != cur_state.fragment_color_clamp.enabled) {
-            glClampColor(GL_CLAMP_FRAGMENT_COLOR_ARB,
-                         fragment_color_clamp.enabled ? GL_TRUE : GL_FALSE);
-        }
+    if (fragment_color_clamp.enabled != cur_state.fragment_color_clamp.enabled) {
+        glClampColor(GL_CLAMP_FRAGMENT_COLOR_ARB,
+                     fragment_color_clamp.enabled ? GL_TRUE : GL_FALSE);
     }
     if (multisample_control.alpha_to_coverage != cur_state.multisample_control.alpha_to_coverage) {
         if (multisample_control.alpha_to_coverage) {
@@ -576,7 +590,7 @@ void OpenGLState::Apply() const {
             glDisable(GL_SAMPLE_ALPHA_TO_ONE);
         }
     }
-
+    ApplyDepthClamp();
     ApplyColorMask();
     ApplyViewport();
     ApplyStencilTest();

src/video_core/renderer_opengl/gl_state.h

@@ -48,6 +48,11 @@ public:
         bool enabled; // GL_CLAMP_FRAGMENT_COLOR_ARB
     } fragment_color_clamp;
 
+    struct {
+        bool far_plane;
+        bool near_plane;
+    } depth_clamp; // GL_DEPTH_CLAMP
+
     struct {
         bool enabled; // viewports arrays are only supported when geometry shaders are enabled.
     } geometry_shaders;
@@ -185,7 +190,7 @@ public:
         GLfloat clamp;
     } polygon_offset;
 
-    std::array<bool, 2> clip_distance; // GL_CLIP_DISTANCE
+    std::array<bool, 8> clip_distance; // GL_CLIP_DISTANCE
 
     OpenGLState();
 
@@ -235,6 +240,7 @@ private:
     void ApplyLogicOp() const;
     void ApplyTextures() const;
     void ApplySamplers() const;
+    void ApplyDepthClamp() const;
     void ApplyPolygonOffset() const;
 };
 

src/video_core/textures/decoders.cpp

@@ -127,7 +127,8 @@ void FastProcessBlock(u8* const swizzled_data, u8* const unswizzled_data, const
 template <bool fast>
 void SwizzledData(u8* const swizzled_data, u8* const unswizzled_data, const bool unswizzle,
                   const u32 width, const u32 height, const u32 depth, const u32 bytes_per_pixel,
-                  const u32 out_bytes_per_pixel, const u32 block_height, const u32 block_depth) {
+                  const u32 out_bytes_per_pixel, const u32 block_height, const u32 block_depth,
+                  const u32 width_spacing) {
     auto div_ceil = [](const u32 x, const u32 y) { return ((x + y - 1) / y); };
     const u32 stride_x = width * out_bytes_per_pixel;
     const u32 layer_z = height * stride_x;
@@ -137,7 +138,8 @@ void SwizzledData(u8* const swizzled_data, u8* const unswizzled_data, const bool
     const u32 block_x_elements = gob_elements_x;
     const u32 block_y_elements = gob_elements_y * block_height;
     const u32 block_z_elements = gob_elements_z * block_depth;
-    const u32 blocks_on_x = div_ceil(width, block_x_elements);
+    const u32 aligned_width = Common::AlignUp(width, gob_elements_x * width_spacing);
+    const u32 blocks_on_x = div_ceil(aligned_width, block_x_elements);
     const u32 blocks_on_y = div_ceil(height, block_y_elements);
     const u32 blocks_on_z = div_ceil(depth, block_z_elements);
     const u32 xy_block_size = gob_size * block_height;
@@ -169,13 +171,15 @@ void SwizzledData(u8* const swizzled_data, u8* const unswizzled_data, const bool
 
 void CopySwizzledData(u32 width, u32 height, u32 depth, u32 bytes_per_pixel,
                       u32 out_bytes_per_pixel, u8* const swizzled_data, u8* const unswizzled_data,
-                      bool unswizzle, u32 block_height, u32 block_depth) {
+                      bool unswizzle, u32 block_height, u32 block_depth, u32 width_spacing) {
     if (bytes_per_pixel % 3 != 0 && (width * bytes_per_pixel) % fast_swizzle_align == 0) {
         SwizzledData<true>(swizzled_data, unswizzled_data, unswizzle, width, height, depth,
-                           bytes_per_pixel, out_bytes_per_pixel, block_height, block_depth);
+                           bytes_per_pixel, out_bytes_per_pixel, block_height, block_depth,
+                           width_spacing);
     } else {
         SwizzledData<false>(swizzled_data, unswizzled_data, unswizzle, width, height, depth,
-                            bytes_per_pixel, out_bytes_per_pixel, block_height, block_depth);
+                            bytes_per_pixel, out_bytes_per_pixel, block_height, block_depth,
+                            width_spacing);
     }
 }
 
@@ -228,19 +232,19 @@ u32 BytesPerPixel(TextureFormat format) {
 
 void UnswizzleTexture(u8* const unswizzled_data, VAddr address, u32 tile_size_x, u32 tile_size_y,
                       u32 bytes_per_pixel, u32 width, u32 height, u32 depth, u32 block_height,
-                      u32 block_depth) {
+                      u32 block_depth, u32 width_spacing) {
     CopySwizzledData((width + tile_size_x - 1) / tile_size_x,
                      (height + tile_size_y - 1) / tile_size_y, depth, bytes_per_pixel,
                      bytes_per_pixel, Memory::GetPointer(address), unswizzled_data, true,
-                     block_height, block_depth);
+                     block_height, block_depth, width_spacing);
 }
 
 std::vector<u8> UnswizzleTexture(VAddr address, u32 tile_size_x, u32 tile_size_y,
                                  u32 bytes_per_pixel, u32 width, u32 height, u32 depth,
-                                 u32 block_height, u32 block_depth) {
+                                 u32 block_height, u32 block_depth, u32 width_spacing) {
     std::vector<u8> unswizzled_data(width * height * depth * bytes_per_pixel);
     UnswizzleTexture(unswizzled_data.data(), address, tile_size_x, tile_size_y, bytes_per_pixel,
-                     width, height, depth, block_height, block_depth);
+                     width, height, depth, block_height, block_depth, width_spacing);
     return unswizzled_data;
 }
 

src/video_core/textures/decoders.h

@@ -22,19 +22,20 @@ inline std::size_t GetGOBSize() {
 void UnswizzleTexture(u8* unswizzled_data, VAddr address, u32 tile_size_x, u32 tile_size_y,
                       u32 bytes_per_pixel, u32 width, u32 height, u32 depth,
                       u32 block_height = TICEntry::DefaultBlockHeight,
-                      u32 block_depth = TICEntry::DefaultBlockHeight);
+                      u32 block_depth = TICEntry::DefaultBlockHeight, u32 width_spacing = 0);
 /**
  * Unswizzles a swizzled texture without changing its format.
  */
 std::vector<u8> UnswizzleTexture(VAddr address, u32 tile_size_x, u32 tile_size_y,
                                  u32 bytes_per_pixel, u32 width, u32 height, u32 depth,
                                  u32 block_height = TICEntry::DefaultBlockHeight,
-                                 u32 block_depth = TICEntry::DefaultBlockHeight);
+                                 u32 block_depth = TICEntry::DefaultBlockHeight,
+                                 u32 width_spacing = 0);
 
 /// Copies texture data from a buffer and performs swizzling/unswizzling as necessary.
 void CopySwizzledData(u32 width, u32 height, u32 depth, u32 bytes_per_pixel,
                       u32 out_bytes_per_pixel, u8* swizzled_data, u8* unswizzled_data,
-                      bool unswizzle, u32 block_height, u32 block_depth);
+                      bool unswizzle, u32 block_height, u32 block_depth, u32 width_spacing);
 
 /**
  * Decodes an unswizzled texture into a A8R8G8B8 texture.

src/video_core/textures/texture.h

@@ -166,6 +166,8 @@ struct TICEntry {
         BitField<3, 3, u32> block_height;
         BitField<6, 3, u32> block_depth;
 
+        BitField<10, 3, u32> tile_width_spacing;
+
         // High 16 bits of the pitch value
         BitField<0, 16, u32> pitch_high;
         BitField<26, 1, u32> use_header_opt_control;

src/yuzu/configuration/configure_input.cpp

@@ -4,11 +4,9 @@
 
 #include <algorithm>
 #include <memory>
-#include <utility>
-#include <QMenu>
-#include <QMessageBox>
+
 #include <QTimer>
-#include "common/param_package.h"
+
 #include "configuration/configure_touchscreen_advanced.h"
 #include "core/core.h"
 #include "core/hle/service/am/am.h"
@@ -16,16 +14,25 @@
 #include "core/hle/service/am/applet_oe.h"
 #include "core/hle/service/hid/controllers/npad.h"
 #include "core/hle/service/sm/sm.h"
-#include "input_common/main.h"
 #include "ui_configure_input.h"
 #include "ui_configure_input_player.h"
-#include "ui_configure_mouse_advanced.h"
-#include "ui_configure_touchscreen_advanced.h"
-#include "yuzu/configuration/config.h"
 #include "yuzu/configuration/configure_input.h"
 #include "yuzu/configuration/configure_input_player.h"
 #include "yuzu/configuration/configure_mouse_advanced.h"
 
+namespace {
+template <typename Dialog, typename... Args>
+void CallConfigureDialog(ConfigureInput& parent, Args&&... args) {
+    parent.applyConfiguration();
+    Dialog dialog(&parent, std::forward<Args>(args)...);
+
+    const auto res = dialog.exec();
+    if (res == QDialog::Accepted) {
+        dialog.applyConfiguration();
+    }
+}
+} // Anonymous namespace
+
 ConfigureInput::ConfigureInput(QWidget* parent)
     : QWidget(parent), ui(std::make_unique<Ui::ConfigureInput>()) {
     ui->setupUi(this);
@@ -65,34 +72,27 @@ ConfigureInput::ConfigureInput(QWidget* parent)
 
     for (std::size_t i = 0; i < players_configure.size(); ++i) {
         connect(players_configure[i], &QPushButton::pressed, this,
-                [this, i]() { CallConfigureDialog<ConfigureInputPlayer>(i, false); });
+                [this, i] { CallConfigureDialog<ConfigureInputPlayer>(*this, i, false); });
     }
 
     connect(ui->handheld_configure, &QPushButton::pressed, this,
-            [this]() { CallConfigureDialog<ConfigureInputPlayer>(8, false); });
+            [this] { CallConfigureDialog<ConfigureInputPlayer>(*this, 8, false); });
 
     connect(ui->debug_configure, &QPushButton::pressed, this,
-            [this]() { CallConfigureDialog<ConfigureInputPlayer>(9, true); });
+            [this] { CallConfigureDialog<ConfigureInputPlayer>(*this, 9, true); });
 
     connect(ui->mouse_advanced, &QPushButton::pressed, this,
-            [this]() { CallConfigureDialog<ConfigureMouseAdvanced>(); });
+            [this] { CallConfigureDialog<ConfigureMouseAdvanced>(*this); });
 
     connect(ui->touchscreen_advanced, &QPushButton::pressed, this,
-            [this]() { CallConfigureDialog<ConfigureTouchscreenAdvanced>(); });
-}
-
-template <typename Dialog, typename... Args>
-void ConfigureInput::CallConfigureDialog(Args&&... args) {
-    this->applyConfiguration();
-    Dialog dialog(this, std::forward<Args>(args)...);
-
-    const auto res = dialog.exec();
-    if (res == QDialog::Accepted) {
-        dialog.applyConfiguration();
-    }
+            [this] { CallConfigureDialog<ConfigureTouchscreenAdvanced>(*this); });
 }
 
 void ConfigureInput::OnDockedModeChanged(bool last_state, bool new_state) {
+    if (ui->use_docked_mode->isChecked() && ui->handheld_connected->isChecked()) {
+        ui->handheld_connected->setChecked(false);
+    }
+
     if (last_state == new_state) {
         return;
     }

src/yuzu/configuration/configure_input.h

@@ -5,20 +5,12 @@
 #pragma once
 
 #include <array>
-#include <functional>
 #include <memory>
-#include <optional>
-#include <string>
-#include <unordered_map>
 
 #include <QKeyEvent>
 #include <QWidget>
 
-#include "common/param_package.h"
-#include "core/settings.h"
-#include "input_common/main.h"
 #include "ui_configure_input.h"
-#include "yuzu/configuration/config.h"
 
 class QPushButton;
 class QString;
@@ -40,9 +32,6 @@ public:
 private:
     void updateUIEnabled();
 
-    template <typename Dialog, typename... Args>
-    void CallConfigureDialog(Args&&... args);
-
     void OnDockedModeChanged(bool last_state, bool new_state);
 
     /// Load configuration settings.

src/yuzu/configuration/configure_input_player.cpp

@@ -25,13 +25,6 @@ const std::array<std::string, ConfigureInputPlayer::ANALOG_SUB_BUTTONS_NUM>
         "modifier",
     }};
 
-static void MoveGridElement(QGridLayout* grid, int row_old, int column_old, int row_new,
-                            int column_new) {
-    const auto item = grid->itemAtPosition(row_old, column_old);
-    // grid->removeItem(item);
-    grid->addItem(item, row_new, column_new);
-}
-
 static void LayerGridElements(QGridLayout* grid, QWidget* item, QWidget* onTopOf) {
     const int index1 = grid->indexOf(item);
     const int index2 = grid->indexOf(onTopOf);
@@ -111,11 +104,10 @@ static QString AnalogToText(const Common::ParamPackage& param, const std::string
     }
 };
 
-ConfigureInputPlayer::ConfigureInputPlayer(QWidget* parent, u8 player_index, bool debug)
-    : QDialog(parent), ui(std::make_unique<Ui::ConfigureInputPlayer>()),
-      timeout_timer(std::make_unique<QTimer>()), poll_timer(std::make_unique<QTimer>()),
-      player_index(player_index), debug(debug) {
-
+ConfigureInputPlayer::ConfigureInputPlayer(QWidget* parent, std::size_t player_index, bool debug)
+    : QDialog(parent), ui(std::make_unique<Ui::ConfigureInputPlayer>()), player_index(player_index),
+      debug(debug), timeout_timer(std::make_unique<QTimer>()),
+      poll_timer(std::make_unique<QTimer>()) {
     ui->setupUi(this);
     setFocusPolicy(Qt::ClickFocus);
 
@@ -315,7 +307,7 @@ ConfigureInputPlayer::ConfigureInputPlayer(QWidget* parent, u8 player_index, boo
 
     for (std::size_t i = 0; i < controller_color_buttons.size(); ++i) {
         connect(controller_color_buttons[i], &QPushButton::clicked, this,
-                std::bind(&ConfigureInputPlayer::OnControllerButtonClick, this, i));
+                [this, i] { OnControllerButtonClick(static_cast<int>(i)); });
     }
 
     this->loadConfiguration();

src/yuzu/configuration/configure_input_player.h

@@ -9,9 +9,10 @@
 #include <memory>
 #include <optional>
 #include <string>
-#include <unordered_map>
+
 #include <QDialog>
 #include <QKeyEvent>
+
 #include "common/param_package.h"
 #include "core/settings.h"
 #include "input_common/main.h"
@@ -29,16 +30,39 @@ class ConfigureInputPlayer : public QDialog {
     Q_OBJECT
 
 public:
-    explicit ConfigureInputPlayer(QWidget* parent, u8 player_index, bool debug = false);
+    explicit ConfigureInputPlayer(QWidget* parent, std::size_t player_index, bool debug = false);
     ~ConfigureInputPlayer() override;
 
     /// Save all button configurations to settings file
     void applyConfiguration();
 
 private:
+    void OnControllerButtonClick(int i);
+
+    /// Load configuration settings.
+    void loadConfiguration();
+    /// Restore all buttons to their default values.
+    void restoreDefaults();
+    /// Clear all input configuration
+    void ClearAll();
+
+    /// Update UI to reflect current configuration.
+    void updateButtonLabels();
+
+    /// Called when the button was pressed.
+    void handleClick(QPushButton* button,
+                     std::function<void(const Common::ParamPackage&)> new_input_setter,
+                     InputCommon::Polling::DeviceType type);
+
+    /// Finish polling and configure input using the input_setter
+    void setPollingResult(const Common::ParamPackage& params, bool abort);
+
+    /// Handle key press events.
+    void keyPressEvent(QKeyEvent* event) override;
+
     std::unique_ptr<Ui::ConfigureInputPlayer> ui;
 
-    u8 player_index;
+    std::size_t player_index;
     bool debug;
 
     std::unique_ptr<QTimer> timeout_timer;
@@ -77,27 +101,4 @@ private:
 
     std::array<QPushButton*, 4> controller_color_buttons;
     std::array<QColor, 4> controller_colors;
-
-    void OnControllerButtonClick(int i);
-
-    /// Load configuration settings.
-    void loadConfiguration();
-    /// Restore all buttons to their default values.
-    void restoreDefaults();
-    /// Clear all input configuration
-    void ClearAll();
-
-    /// Update UI to reflect current configuration.
-    void updateButtonLabels();
-
-    /// Called when the button was pressed.
-    void handleClick(QPushButton* button,
-                     std::function<void(const Common::ParamPackage&)> new_input_setter,
-                     InputCommon::Polling::DeviceType type);
-
-    /// Finish polling and configure input using the input_setter
-    void setPollingResult(const Common::ParamPackage& params, bool abort);
-
-    /// Handle key press events.
-    void keyPressEvent(QKeyEvent* event) override;
 };

src/yuzu/configuration/configure_mouse_advanced.cpp

@@ -4,11 +4,11 @@
 
 #include <algorithm>
 #include <memory>
-#include <utility>
+
 #include <QKeyEvent>
 #include <QMenu>
-#include <QMessageBox>
 #include <QTimer>
+
 #include "common/assert.h"
 #include "common/param_package.h"
 #include "input_common/main.h"

src/yuzu/configuration/configure_mouse_advanced.h

@@ -7,7 +7,7 @@
 #include <memory>
 #include <optional>
 #include <QDialog>
-#include <QWidget>
+
 #include "core/settings.h"
 
 class QCheckBox;
@@ -28,23 +28,6 @@ public:
     void applyConfiguration();
 
 private:
-    std::unique_ptr<Ui::ConfigureMouseAdvanced> ui;
-
-    /// This will be the the setting function when an input is awaiting configuration.
-    std::optional<std::function<void(const Common::ParamPackage&)>> input_setter;
-
-    std::array<QPushButton*, Settings::NativeMouseButton::NumMouseButtons> button_map;
-    std::array<Common::ParamPackage, Settings::NativeMouseButton::NumMouseButtons> buttons_param;
-
-    std::vector<std::unique_ptr<InputCommon::Polling::DevicePoller>> device_pollers;
-
-    std::unique_ptr<QTimer> timeout_timer;
-    std::unique_ptr<QTimer> poll_timer;
-
-    /// A flag to indicate if keyboard keys are okay when configuring an input. If this is false,
-    /// keyboard events are ignored.
-    bool want_keyboard_keys = false;
-
     /// Load configuration settings.
     void loadConfiguration();
     /// Restore all buttons to their default values.
@@ -65,4 +48,21 @@ private:
 
     /// Handle key press events.
     void keyPressEvent(QKeyEvent* event) override;
+
+    std::unique_ptr<Ui::ConfigureMouseAdvanced> ui;
+
+    /// This will be the the setting function when an input is awaiting configuration.
+    std::optional<std::function<void(const Common::ParamPackage&)>> input_setter;
+
+    std::array<QPushButton*, Settings::NativeMouseButton::NumMouseButtons> button_map;
+    std::array<Common::ParamPackage, Settings::NativeMouseButton::NumMouseButtons> buttons_param;
+
+    std::vector<std::unique_ptr<InputCommon::Polling::DevicePoller>> device_pollers;
+
+    std::unique_ptr<QTimer> timeout_timer;
+    std::unique_ptr<QTimer> poll_timer;
+
+    /// A flag to indicate if keyboard keys are okay when configuring an input. If this is false,
+    /// keyboard events are ignored.
+    bool want_keyboard_keys = false;
 };

src/yuzu/main.cpp

@@ -1105,14 +1105,14 @@ void GMainWindow::OnMenuInstallToNAND() {
             return;
         }
         const auto res =
-            Service::FileSystem::GetUserNANDContents()->InstallEntry(nsp, false, qt_raw_copy);
+            Service::FileSystem::GetUserNANDContents()->InstallEntry(*nsp, false, qt_raw_copy);
         if (res == FileSys::InstallResult::Success) {
             success();
         } else {
             if (res == FileSys::InstallResult::ErrorAlreadyExists) {
                 if (overwrite()) {
                     const auto res2 = Service::FileSystem::GetUserNANDContents()->InstallEntry(
-                        nsp, true, qt_raw_copy);
+                        *nsp, true, qt_raw_copy);
                     if (res2 == FileSys::InstallResult::Success) {
                         success();
                     } else {
@@ -1167,10 +1167,10 @@ void GMainWindow::OnMenuInstallToNAND() {
         FileSys::InstallResult res;
         if (index >= static_cast<size_t>(FileSys::TitleType::Application)) {
             res = Service::FileSystem::GetUserNANDContents()->InstallEntry(
-                nca, static_cast<FileSys::TitleType>(index), false, qt_raw_copy);
+                *nca, static_cast<FileSys::TitleType>(index), false, qt_raw_copy);
         } else {
             res = Service::FileSystem::GetSystemNANDContents()->InstallEntry(
-                nca, static_cast<FileSys::TitleType>(index), false, qt_raw_copy);
+                *nca, static_cast<FileSys::TitleType>(index), false, qt_raw_copy);
         }
 
         if (res == FileSys::InstallResult::Success) {
@@ -1178,7 +1178,7 @@ void GMainWindow::OnMenuInstallToNAND() {
         } else if (res == FileSys::InstallResult::ErrorAlreadyExists) {
             if (overwrite()) {
                 const auto res2 = Service::FileSystem::GetUserNANDContents()->InstallEntry(
-                    nca, static_cast<FileSys::TitleType>(index), true, qt_raw_copy);
+                    *nca, static_cast<FileSys::TitleType>(index), true, qt_raw_copy);
                 if (res2 == FileSys::InstallResult::Success) {
                     success();
                 } else {