Add missing environment variables to travis-ci.env

.travis/common/travis-ci.env

@@ -6,6 +6,8 @@ TRAVIS_BRANCH
 TRAVIS_BUILD_ID
 TRAVIS_BUILD_NUMBER
 TRAVIS_COMMIT
+TRAVIS_COMMIT_RANGE
+TRAVIS_EVENT_TYPE
 TRAVIS_JOB_ID
 TRAVIS_JOB_NUMBER
 TRAVIS_REPO_SLUG

src/core/hle/kernel/svc.cpp

@@ -63,77 +63,43 @@ 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)) {
-        LOG_ERROR(Kernel_SVC, "Destination address is not aligned to 4KB, 0x{:016X}", dst_addr);
+    if (!Common::Is4KBAligned(dst_addr) || !Common::Is4KBAligned(src_addr)) {
         return ERR_INVALID_ADDRESS;
     }
 
-    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);
+    if (size == 0 || !Common::Is4KBAligned(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;
     }
 
@@ -177,15 +143,8 @@ 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 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);
+    // Size must be a multiple of 0x200000 (2MB) and be equal to or less than 4GB.
+    if ((heap_size & 0xFFFFFFFE001FFFFF) != 0) {
         return ERR_INVALID_SIZE;
     }
 
@@ -200,31 +159,20 @@ 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) {
-        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);
+    if (size == 0 || !Common::Is4KBAligned(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;
     }
 
@@ -232,15 +180,11 @@ 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;
     }
 
@@ -295,9 +239,6 @@ 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;
     }
 
@@ -305,8 +246,6 @@ 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;
     }
 
@@ -355,7 +294,6 @@ 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;
     }
 
@@ -370,8 +308,6 @@ 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;
     }
 
@@ -401,18 +337,12 @@ 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)) {
-        LOG_ERROR(Kernel_SVC,
-                  "Handle address is not a valid virtual address, handle_address=0x{:016X}",
-                  handles_address);
+    if (!Memory::IsValidVirtualAddress(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;
     }
 
@@ -427,7 +357,6 @@ 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;
         }
 
@@ -451,13 +380,11 @@ 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);
@@ -478,8 +405,6 @@ 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;
     }
 
@@ -498,13 +423,10 @@ 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;
     }
 
@@ -518,13 +440,10 @@ 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;
     }
 
@@ -715,14 +634,10 @@ static ResultCode GetInfo(u64* result, u64 info_id, u64 handle, u64 info_sub_id)
         break;
     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;
         }
 
@@ -760,16 +675,12 @@ static ResultCode GetInfo(u64* result, u64 info_id, u64 handle, u64 info_sub_id)
     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));
         if (!thread) {
-            LOG_ERROR(Kernel_SVC, "Thread handle does not exist, handle=0x{:08X}",
-                      static_cast<Handle>(handle));
             return ERR_INVALID_HANDLE;
         }
 
@@ -812,22 +723,14 @@ 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;
     }
 
@@ -848,12 +751,9 @@ 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;
     }
 
@@ -863,13 +763,7 @@ 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;
     }
 
@@ -877,7 +771,6 @@ 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;
     }
 
@@ -900,46 +793,32 @@ 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) {
-        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);
+    if (size == 0 || !Common::Is4KBAligned(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, "Expected Read or ReadWrite permission but got permissions=0x{:08X}",
-                  permissions);
+        LOG_ERROR(Kernel_SVC, "Invalid 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;
     }
 
@@ -951,38 +830,25 @@ 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) {
-        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);
+    if (size == 0 || !Common::Is4KBAligned(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;
     }
 
@@ -992,12 +858,9 @@ 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);
@@ -1013,6 +876,8 @@ 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;
 }
 
@@ -1041,14 +906,7 @@ 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, name, 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;
     }
 
@@ -1079,8 +937,6 @@ 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);
@@ -1088,6 +944,11 @@ 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;
 }
 
@@ -1098,8 +959,6 @@ 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;
     }
 
@@ -1279,12 +1138,10 @@ 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 (!Common::IsWordAligned(address)) {
-        LOG_ERROR(Kernel_SVC, "Address is not word aligned, address={:016X}", address);
+    if (address % sizeof(u32) != 0) {
         return ERR_INVALID_ADDRESS;
     }
 
@@ -1296,10 +1153,6 @@ 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;
     }
 }
@@ -1310,12 +1163,10 @@ 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 (!Common::IsWordAligned(address)) {
-        LOG_ERROR(Kernel_SVC, "Address is not word aligned, address={:016X}", address);
+    if (address % sizeof(u32) != 0) {
         return ERR_INVALID_ADDRESS;
     }
 
@@ -1328,18 +1179,12 @@ 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.
@@ -1413,8 +1258,6 @@ 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;
     }
 
@@ -1425,14 +1268,12 @@ 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{:016X}, core=0x{:X}", thread_handle,
+    LOG_DEBUG(Kernel_SVC, "called, handle=0x{:08X}, mask=0x{:16X}, 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;
     }
 
@@ -1447,7 +1288,6 @@ static ResultCode SetThreadCoreMask(Handle thread_handle, u32 core, u64 mask) {
     }
 
     if (mask == 0) {
-        LOG_ERROR(Kernel_SVC, "Mask is 0");
         return ERR_INVALID_COMBINATION;
     }
 
@@ -1457,14 +1297,11 @@ 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;
     }
 
@@ -1477,36 +1314,21 @@ 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;
-    }
 
-    if (size >= MAIN_MEMORY_SIZE) {
-        LOG_ERROR(Kernel_SVC, "Size is not less than 8GB, 0x{:016X}", 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) {
         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;
     }
 
@@ -1526,7 +1348,6 @@ 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;
     }
 
@@ -1545,14 +1366,11 @@ 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

@@ -207,11 +207,10 @@ 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) {
@@ -228,10 +227,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/am/am.cpp

@@ -217,7 +217,6 @@ 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};
 
@@ -230,40 +229,44 @@ 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) {
@@ -272,45 +275,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");
@@ -319,31 +322,32 @@ 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() {
@@ -434,49 +438,47 @@ 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);
 
@@ -491,6 +493,8 @@ 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)
@@ -513,21 +517,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> {
@@ -562,34 +566,32 @@ 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();
@@ -597,39 +599,36 @@ 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>());
 
@@ -639,52 +638,51 @@ 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)
@@ -703,27 +701,21 @@ 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);
     }
@@ -732,20 +724,17 @@ 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);
     }
@@ -754,6 +743,8 @@ 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") {
@@ -792,8 +783,6 @@ 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;
@@ -803,23 +792,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);
@@ -830,7 +819,6 @@ 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;
@@ -894,45 +882,38 @@ 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;
@@ -951,19 +932,21 @@ 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};
@@ -978,62 +961,60 @@ 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,
@@ -1070,10 +1051,9 @@ 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,75 +32,66 @@ 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;
@@ -131,110 +122,97 @@ 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,67 +35,59 @@ 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;
@@ -103,11 +95,10 @@ 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,8 +68,6 @@ 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);
 
@@ -84,7 +82,6 @@ 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();
 
@@ -113,8 +110,6 @@ 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();
@@ -133,6 +128,7 @@ 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,22 +40,24 @@ 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));
     }
 };
 
@@ -71,11 +73,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"} {
@@ -96,11 +98,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,7 +86,6 @@ 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));
@@ -149,7 +148,6 @@ 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)};
@@ -165,7 +163,6 @@ 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};
@@ -175,7 +172,6 @@ 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()));
@@ -193,7 +189,6 @@ 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,79 +52,74 @@ 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) {
@@ -216,7 +211,6 @@ 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);
@@ -241,20 +235,19 @@ 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;
@@ -308,26 +301,26 @@ void AudRenU::GetAudioRendererWorkBufferSize(Kernel::HLERequestContext& ctx) {
     rb.Push(RESULT_SUCCESS);
     rb.Push<u64>(output_sz);
 
-    LOG_DEBUG(Service_Audio, "buffer_size=0x{:X}", output_sz);
+    LOG_DEBUG(Service_Audio, "called, 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>(); // TODO(ogniK): Figure out what is different
-                                                // based on the current revision
+    rb.PushIpcInterface<Audio::IAudioDevice>();
+
+    LOG_WARNING(Service_Audio, "(STUBBED) called"); // 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,13 +46,10 @@ 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));
@@ -66,15 +63,12 @@ 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));
@@ -94,39 +88,24 @@ 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()) {
-            LOG_ERROR(Audio, "Input is smaller than the header size, header_sz={}, input_sz={}",
-                      sizeof(OpusHeader), input.size());
+        if (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) {
-            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);
+        if (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(), 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));
+            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)
             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);
@@ -155,17 +134,14 @@ static std::size_t WorkerBufferSize(u32 channel_count) {
 
 void HwOpus::GetWorkBufferSize(Kernel::HLERequestContext& ctx) {
     IPC::RequestParser rp{ctx};
-    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);
-
+    auto sample_rate = rp.Pop<u32>();
+    auto channel_count = rp.Pop<u32>();
     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");
-
-    const u32 worker_buffer_sz = static_cast<u32>(WorkerBufferSize(channel_count));
-    LOG_DEBUG(Audio, "worker_buffer_sz={}", worker_buffer_sz);
+    u32 worker_buffer_sz = static_cast<u32>(WorkerBufferSize(channel_count));
+    LOG_DEBUG(Audio, "called worker_buffer_sz={}", worker_buffer_sz);
 
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
@@ -179,7 +155,6 @@ 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");
@@ -189,8 +164,7 @@ 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 (const int err = opus_decoder_init(decoder.get(), sample_rate, channel_count)) {
-        LOG_ERROR(Audio, "Failed to init opus decoder with error={}", err);
+    if (opus_decoder_init(decoder.get(), sample_rate, channel_count)) {
         IPC::ResponseBuilder rb{ctx, 2};
         // TODO(ogniK): Use correct error code
         rb.Push(ResultCode(-1));

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

@@ -33,11 +33,10 @@ 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,14 +34,13 @@ 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,44 +57,40 @@ 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;
@@ -115,11 +111,10 @@ 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");
     }
 };
 
@@ -214,11 +209,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,13 +62,11 @@ 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;
@@ -109,13 +107,11 @@ 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;
@@ -142,13 +138,11 @@ 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;
@@ -186,9 +180,8 @@ private:
     void SetSize(Kernel::HLERequestContext& ctx) {
         IPC::RequestParser rp{ctx};
         const u64 size = rp.Pop<u64>();
-        LOG_DEBUG(Service_FS, "called, size={}", size);
-
         backend->Resize(size);
+        LOG_DEBUG(Service_FS, "called, size={}", size);
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
@@ -472,8 +465,6 @@ 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);
 
@@ -712,8 +703,6 @@ 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));
@@ -749,7 +738,6 @@ 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);
@@ -775,7 +763,6 @@ 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,8 +524,6 @@ 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;
     }
@@ -535,6 +533,7 @@ 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();
 }
 
@@ -576,8 +575,8 @@ void Controller_NPad::AddNewControllerAt(NPadControllerType controller, u32 npad
         return;
     }
 
-    connected_controllers[NPadIdToIndex(npad_id)] = {controller, true};
-    InitNewlyAddedControler(NPadIdToIndex(npad_id));
+    connected_controllers[npad_id] = {controller, true};
+    InitNewlyAddedControler(npad_id);
 }
 
 void Controller_NPad::ConnectNPad(u32 npad_id) {

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

@@ -124,11 +124,10 @@ 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) {
@@ -164,10 +163,9 @@ 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");
     }
 };
 
@@ -305,8 +303,6 @@ 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>();
         }
@@ -314,228 +310,206 @@ 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);
 
@@ -553,96 +527,86 @@ 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,133 +44,115 @@ 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,8 +97,6 @@ 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!");
@@ -191,7 +189,6 @@ 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);
@@ -222,10 +219,6 @@ 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!");
@@ -352,8 +345,6 @@ 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!");
@@ -402,12 +393,11 @@ 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,14 +31,12 @@ 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);
     }
@@ -47,16 +45,15 @@ private:
         IPC::RequestParser rp{ctx};
         min = rp.Pop<u32>();
         max = rp.Pop<u32>();
-        LOG_WARNING(Service_MM, "(STUBBED) called, min=0x{:X}, max=0x{:X}", min, max);
-
         current = min;
+
+        LOG_WARNING(Service_MM, "(STUBBED) called, min=0x{:X}, max=0x{:X}", min, max);
         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);
@@ -64,7 +61,6 @@ 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
@@ -72,7 +68,6 @@ private:
 
     void FinalizeWithId(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_MM, "(STUBBED) called");
-
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
     }
@@ -82,17 +77,16 @@ 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,29 +108,30 @@ 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);
@@ -140,7 +141,6 @@ 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,7 +150,6 @@ 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());
@@ -169,7 +168,6 @@ private:
 
     void StopDetection(Kernel::HLERequestContext& ctx) {
         LOG_DEBUG(Service_NFP, "called");
-
         switch (device_state) {
         case DeviceState::TagFound:
         case DeviceState::TagNearby:
@@ -187,7 +185,6 @@ 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;
@@ -326,7 +323,6 @@ 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,14 +63,12 @@ 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);
@@ -78,14 +76,12 @@ 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);
@@ -93,14 +89,12 @@ 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);
     }
@@ -128,36 +122,32 @@ 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();
@@ -168,24 +158,23 @@ 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);
@@ -246,19 +235,17 @@ 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,53 +148,47 @@ 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");
     }
 };
 
@@ -214,26 +208,23 @@ 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,7 +281,6 @@ 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);
 }
@@ -289,8 +288,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);
 
+    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));
@@ -299,8 +298,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);
 
+    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);
@@ -309,8 +308,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);
 
+    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);
@@ -318,7 +317,6 @@ 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);
@@ -330,6 +328,7 @@ 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);
@@ -339,7 +338,6 @@ 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,7 +54,6 @@ 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;
 }
 
@@ -192,7 +191,6 @@ 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,7 +103,6 @@ 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());
@@ -116,7 +115,6 @@ 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());
@@ -128,7 +126,6 @@ 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) {
@@ -151,7 +148,6 @@ 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?
@@ -161,7 +157,6 @@ 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
@@ -171,7 +166,6 @@ 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
@@ -181,7 +175,6 @@ 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,6 +8,7 @@
 #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"
 
@@ -60,14 +61,12 @@ 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;
@@ -76,7 +75,6 @@ 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;
@@ -88,7 +86,6 @@ 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;
 }
@@ -98,7 +95,6 @@ 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;
 }
@@ -106,7 +102,6 @@ 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;
 }
 
@@ -118,7 +113,6 @@ 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());
@@ -130,18 +124,11 @@ 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();
@@ -155,11 +142,11 @@ u32 nvhost_gpu::SubmitGPFIFO(const std::vector<u8>& input, std::vector<u8>& outp
                                    params.num_entries * sizeof(Tegra::CommandListHeader),
                "Incorrect input size");
 
-    Tegra::CommandList entries(params.num_entries);
+    std::vector<Tegra::CommandListHeader> entries(params.num_entries);
     std::memcpy(entries.data(), &input[sizeof(IoctlSubmitGpfifo)],
                 params.num_entries * sizeof(Tegra::CommandListHeader));
 
-    PushGPUEntries(std::move(entries));
+    Core::System::GetInstance().GPU().ProcessCommandLists(entries);
 
     params.fence_out.id = 0;
     params.fence_out.value = 0;
@@ -176,11 +163,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);
 
-    Tegra::CommandList entries(params.num_entries);
+    std::vector<Tegra::CommandListHeader> entries(params.num_entries);
     Memory::ReadBlock(params.address, entries.data(),
                       params.num_entries * sizeof(Tegra::CommandListHeader));
 
-    PushGPUEntries(std::move(entries));
+    Core::System::GetInstance().GPU().ProcessCommandLists(entries);
 
     params.fence_out.id = 0;
     params.fence_out.value = 0;
@@ -192,7 +179,6 @@ 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;
@@ -202,7 +188,6 @@ 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,7 +30,6 @@ 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,7 +30,6 @@ 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,7 +30,6 @@ 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,7 +54,6 @@ 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.
@@ -79,12 +78,10 @@ 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);
     }
 
@@ -95,12 +92,10 @@ 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);
     }
 
@@ -121,13 +116,11 @@ 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);
     }
 
@@ -146,13 +139,11 @@ 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);
     }
 
@@ -175,12 +166,10 @@ 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);
     }
 
@@ -220,14 +209,9 @@ 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,7 +55,6 @@ 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);
@@ -76,8 +75,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);
 
+    LOG_WARNING(Service_NVDRV, "(STUBBED) called, pid=0x{:X}", pid);
     IPC::ResponseBuilder rb{ctx, 3};
     rb.Push(RESULT_SUCCESS);
     rb.Push<u32>(0);
@@ -85,14 +84,12 @@ 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);
 }
@@ -101,7 +98,6 @@ 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,7 +92,6 @@ 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,33 +114,29 @@ 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

@@ -49,39 +49,38 @@ 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) {
-    LOG_DEBUG(Service_SET, "called");
-
-    if (available_language_codes.size() > pre4_0_0_max_entries) {
+    if (available_language_codes.size() > pre4_0_0_max_entries)
         ctx.WriteBuffer(MakeLanguageCodeSubset<pre4_0_0_max_entries>());
-    } else {
+    else
         ctx.WriteBuffer(available_language_codes);
-    }
+
     PushResponseLanguageCode(ctx, pre4_0_0_max_entries);
+
+    LOG_DEBUG(Service_SET, "called");
 }
 
 void SET::GetAvailableLanguageCodes2(Kernel::HLERequestContext& ctx) {
-    LOG_DEBUG(Service_SET, "called");
-
-    if (available_language_codes.size() > post4_0_0_max_entries) {
+    if (available_language_codes.size() > post4_0_0_max_entries)
         ctx.WriteBuffer(MakeLanguageCodeSubset<post4_0_0_max_entries>());
-    } else {
+    else
         ctx.WriteBuffer(available_language_codes);
-    }
+
     PushResponseLanguageCode(ctx, post4_0_0_max_entries);
+
+    LOG_DEBUG(Service_SET, "called");
 }
 
 void SET::GetAvailableLanguageCodeCount(Kernel::HLERequestContext& ctx) {
-    LOG_DEBUG(Service_SET, "called");
-
     PushResponseLanguageCode(ctx, pre4_0_0_max_entries);
+
+    LOG_DEBUG(Service_SET, "called");
 }
 
 void SET::GetAvailableLanguageCodeCount2(Kernel::HLERequestContext& ctx) {
@@ -91,11 +90,11 @@ 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);
 }
 
 SET::SET() : ServiceFramework("set") {

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,26 +14,25 @@ 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, "session={}", session->GetObjectId());
+    LOG_DEBUG(Service, "called, session={}", session->GetObjectId());
 }
 
 void Controller::DuplicateSessionEx(Kernel::HLERequestContext& ctx) {
@@ -43,11 +42,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,10 +103,9 @@ 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) {
@@ -173,7 +172,6 @@ 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,8 +24,6 @@ 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();
@@ -38,6 +36,7 @@ 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,7 +69,6 @@ public:
 private:
     void SetOption(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_SSL, "(STUBBED) called");
-
         IPC::RequestParser rp{ctx};
 
         IPC::ResponseBuilder rb{ctx, 2};
@@ -115,7 +114,6 @@ 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,7 +72,6 @@ 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);
@@ -80,7 +79,6 @@ 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);
@@ -100,7 +98,6 @@ 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};
@@ -133,7 +130,6 @@ 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);
@@ -141,7 +137,6 @@ 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);
@@ -159,6 +154,7 @@ 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{};
@@ -179,6 +175,7 @@ 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};
@@ -195,7 +192,6 @@ 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, {});
@@ -208,7 +204,6 @@ 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, {});
@@ -221,43 +216,38 @@ 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) {
@@ -275,7 +265,6 @@ 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>();
-        LOG_DEBUG(Service_VI, "called, transaction={:X}", static_cast<u32>(transaction));
-
         auto buffer_queue = nv_flinger->GetBufferQueue(id);
 
+        LOG_DEBUG(Service_VI, "called, transaction={:X}", static_cast<u32>(transaction));
+
         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,11 +604,12 @@ 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());
@@ -672,7 +673,6 @@ 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,16 +685,13 @@ private:
         IPC::RequestParser rp{ctx};
         u64 layer_id = rp.Pop<u64>();
         bool visibility = rp.Pop<bool>();
-        LOG_WARNING(Service_VI, "(STUBBED) called, layer_id=0x{:08X}, visibility={}", layer_id,
-                    visibility);
-
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
+        LOG_WARNING(Service_VI, "(STUBBED) called, layer_id=0x{:08X}, visibility={}", layer_id,
+                    visibility);
     }
 
     void GetDisplayMode(Kernel::HLERequestContext& ctx) {
-        LOG_WARNING(Service_VI, "(STUBBED) called");
-
         IPC::ResponseBuilder rb{ctx, 6};
         rb.Push(RESULT_SUCCESS);
 
@@ -710,8 +707,10 @@ private:
                     static_cast<u32>(Settings::values.resolution_factor));
         }
 
-        rb.PushRaw<float>(60.0f); // This wouldn't seem to be correct for 30 fps games.
+        rb.PushRaw<float>(60.0f);
         rb.Push<u32>(0);
+
+        LOG_DEBUG(Service_VI, "called");
     }
 };
 
@@ -794,7 +793,6 @@ public:
 private:
     void CloseDisplay(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
-
         IPC::RequestParser rp{ctx};
         u64 display = rp.Pop<u64>();
 
@@ -804,7 +802,6 @@ 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);
@@ -820,7 +817,6 @@ 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>();
@@ -833,11 +829,10 @@ private:
         IPC::RequestParser rp{ctx};
         u64 layer_id = rp.Pop<u64>();
         bool visibility = rp.Pop<bool>();
-        LOG_WARNING(Service_VI, "(STUBBED) called, layer_id=0x{:X}, visibility={}", layer_id,
-                    visibility);
-
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(RESULT_SUCCESS);
+        LOG_WARNING(Service_VI, "(STUBBED) called, layer_id=0x{:X}, visibility={}", layer_id,
+                    visibility);
     }
 
     std::shared_ptr<NVFlinger::NVFlinger> nv_flinger;
@@ -883,7 +878,6 @@ 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');
@@ -899,7 +893,6 @@ private:
 
     void CloseDisplay(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
-
         IPC::RequestParser rp{ctx};
         u64 display_id = rp.Pop<u64>();
 
@@ -909,7 +902,6 @@ private:
 
     void GetDisplayResolution(Kernel::HLERequestContext& ctx) {
         LOG_WARNING(Service_VI, "(STUBBED) called");
-
         IPC::RequestParser rp{ctx};
         u64 display_id = rp.Pop<u64>();
 
@@ -931,7 +923,6 @@ 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>();
@@ -941,8 +932,6 @@ 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);
@@ -951,11 +940,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');
@@ -1006,7 +995,6 @@ 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
-    dma_pusher.cpp
-    dma_pusher.h
+    command_processor.cpp
+    command_processor.h
     debug_utils/debug_utils.cpp
     debug_utils/debug_utils.h
     engines/fermi_2d.cpp

src/video_core/command_processor.h

@@ -0,0 +1,53 @@
+// 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

@@ -1,123 +0,0 @@
-// 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

@@ -1,99 +0,0 @@
-// 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<6E>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::CallMethod(const GPU::MethodCall& method_call) {
-    ASSERT_MSG(method_call.method < Regs::NUM_REGS,
+void Fermi2D::WriteReg(u32 method, u32 value) {
+    ASSERT_MSG(method < Regs::NUM_REGS,
                "Invalid Fermi2D register, increase the size of the Regs structure");
 
-    regs.reg_array[method_call.method] = method_call.argument;
+    regs.reg_array[method] = value;
 
-    switch (method_call.method) {
+    switch (method) {
     case FERMI2D_REG_INDEX(trigger): {
         HandleSurfaceCopy();
         break;

src/video_core/engines/fermi_2d.h

@@ -27,7 +27,7 @@ public:
     ~Fermi2D() = default;
 
     /// Write the value to the register identified by method.
-    void CallMethod(const GPU::MethodCall& method_call);
+    void WriteReg(u32 method, u32 value);
 
     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::CallMethod(const GPU::MethodCall& method_call) {
-    ASSERT_MSG(method_call.method < Regs::NUM_REGS,
+void KeplerMemory::WriteReg(u32 method, u32 value) {
+    ASSERT_MSG(method < Regs::NUM_REGS,
                "Invalid KeplerMemory register, increase the size of the Regs structure");
 
-    regs.reg_array[method_call.method] = method_call.argument;
+    regs.reg_array[method] = value;
 
-    switch (method_call.method) {
+    switch (method) {
     case KEPLERMEMORY_REG_INDEX(exec): {
         state.write_offset = 0;
         break;
     }
     case KEPLERMEMORY_REG_INDEX(data): {
-        ProcessData(method_call.argument);
+        ProcessData(value);
         break;
     }
     }

src/video_core/engines/kepler_memory.h

@@ -9,7 +9,6 @@
 #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 {
@@ -27,7 +26,7 @@ public:
     ~KeplerMemory();
 
     /// Write the value to the register identified by method.
-    void CallMethod(const GPU::MethodCall& method_call);
+    void WriteReg(u32 method, u32 value);
 
     struct Regs {
         static constexpr size_t NUM_REGS = 0x7F;

src/video_core/engines/maxwell_3d.cpp

@@ -97,74 +97,71 @@ void Maxwell3D::CallMacroMethod(u32 method, std::vector<u32> parameters) {
     macro_interpreter.Execute(search->second, std::move(parameters));
 }
 
-void Maxwell3D::CallMethod(const GPU::MethodCall& method_call) {
+void Maxwell3D::WriteReg(u32 method, u32 value, u32 remaining_params) {
     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_call.method == executing_macro + 1);
+        ASSERT(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_call.method >= MacroRegistersStart) {
+    if (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_call.method % 2) == 0,
+            ASSERT_MSG((method % 2) == 0,
                        "Can't start macro execution by writing to the ARGS register");
-            executing_macro = method_call.method;
+            executing_macro = method;
         }
 
-        macro_params.push_back(method_call.argument);
+        macro_params.push_back(value);
 
         // Call the macro when there are no more parameters in the command buffer
-        if (method_call.IsLastCall()) {
+        if (remaining_params == 0) {
             CallMacroMethod(executing_macro, std::move(macro_params));
         }
         return;
     }
 
-    ASSERT_MSG(method_call.method < Regs::NUM_REGS,
+    ASSERT_MSG(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_call.method] != method_call.argument) {
-        regs.reg_array[method_call.method] = method_call.argument;
+    if (regs.reg_array[method] != value) {
+        regs.reg_array[method] = value;
         // Vertex format
-        if (method_call.method >= MAXWELL3D_REG_INDEX(vertex_attrib_format) &&
-            method_call.method <
-                MAXWELL3D_REG_INDEX(vertex_attrib_format) + regs.vertex_attrib_format.size()) {
+        if (method >= MAXWELL3D_REG_INDEX(vertex_attrib_format) &&
+            method < MAXWELL3D_REG_INDEX(vertex_attrib_format) + regs.vertex_attrib_format.size()) {
             dirty_flags.vertex_attrib_format = true;
         }
 
         // Vertex buffer
-        if (method_call.method >= MAXWELL3D_REG_INDEX(vertex_array) &&
-            method_call.method < MAXWELL3D_REG_INDEX(vertex_array) + 4 * 32) {
+        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) {
             dirty_flags.vertex_array |=
-                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));
+                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));
         }
     }
 
-    switch (method_call.method) {
+    switch (method) {
     case MAXWELL3D_REG_INDEX(macros.data): {
-        ProcessMacroUpload(method_call.argument);
+        ProcessMacroUpload(value);
         break;
     }
     case MAXWELL3D_REG_INDEX(macros.bind): {
-        ProcessMacroBind(method_call.argument);
+        ProcessMacroBind(value);
         break;
     }
     case MAXWELL3D_REG_INDEX(const_buffer.cb_data[0]):
@@ -183,7 +180,7 @@ void Maxwell3D::CallMethod(const GPU::MethodCall& method_call) {
     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(method_call.argument);
+        ProcessCBData(value);
         break;
     }
     case MAXWELL3D_REG_INDEX(cb_bind[0].raw_config): {

src/video_core/engines/maxwell_3d.h

@@ -744,20 +744,7 @@ public:
 
                 u32 vb_element_base;
 
-                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);
+                INSERT_PADDING_WORDS(0x38);
 
                 float point_size;
 
@@ -915,15 +902,8 @@ public:
 
                 u32 viewport_transform_enabled;
 
-                INSERT_PADDING_WORDS(0x3);
+                INSERT_PADDING_WORDS(0x25);
 
-                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;
@@ -1100,7 +1080,7 @@ public:
     u32 GetRegisterValue(u32 method) const;
 
     /// Write the value to the register identified by method.
-    void CallMethod(const GPU::MethodCall& method_call);
+    void WriteReg(u32 method, u32 value, u32 remaining_params);
 
     /// Returns a list of enabled textures for the specified shader stage.
     std::vector<Texture::FullTextureInfo> GetStageTextures(Regs::ShaderStage stage) const;
@@ -1221,7 +1201,6 @@ 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);
@@ -1245,7 +1224,6 @@ 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::CallMethod(const GPU::MethodCall& method_call) {
-    ASSERT_MSG(method_call.method < Regs::NUM_REGS,
+void MaxwellCompute::WriteReg(u32 method, u32 value) {
+    ASSERT_MSG(method < Regs::NUM_REGS,
                "Invalid MaxwellCompute register, increase the size of the Regs structure");
 
-    regs.reg_array[method_call.method] = method_call.argument;
+    regs.reg_array[method] = value;
 
-    switch (method_call.method) {
+    switch (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,7 +9,6 @@
 #include "common/bit_field.h"
 #include "common/common_funcs.h"
 #include "common/common_types.h"
-#include "video_core/gpu.h"
 
 namespace Tegra::Engines {
 
@@ -43,7 +42,7 @@ public:
                   "MaxwellCompute Regs has wrong size");
 
     /// Write the value to the register identified by method.
-    void CallMethod(const GPU::MethodCall& method_call);
+    void WriteReg(u32 method, u32 value);
 };
 
 #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::CallMethod(const GPU::MethodCall& method_call) {
-    ASSERT_MSG(method_call.method < Regs::NUM_REGS,
+void MaxwellDMA::WriteReg(u32 method, u32 value) {
+    ASSERT_MSG(method < Regs::NUM_REGS,
                "Invalid MaxwellDMA register, increase the size of the Regs structure");
 
-    regs.reg_array[method_call.method] = method_call.argument;
+    regs.reg_array[method] = value;
 
 #define MAXWELLDMA_REG_INDEX(field_name)                                                           \
     (offsetof(Tegra::Engines::MaxwellDMA::Regs, field_name) / sizeof(u32))
 
-    switch (method_call.method) {
+    switch (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 CallMethod(const GPU::MethodCall& method_call);
+    void WriteReg(u32 method, u32 value);
 
     struct Regs {
         static constexpr std::size_t NUM_REGS = 0x1D6;

src/video_core/gpu.cpp

@@ -26,7 +26,6 @@ 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>();
@@ -52,14 +51,6 @@ 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);
 
@@ -122,48 +113,4 @@ 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 {} value "
-              "{:08X} remaining params {}",
-              MethCall.method, MethCall.subchannel, value, remaining_params);
-
-    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,7 +9,6 @@
 #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 {
@@ -120,23 +119,8 @@ public:
     explicit GPU(VideoCore::RasterizerInterface& rasterizer);
     ~GPU();
 
-    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);
+    /// Processes a command list stored at the specified address in GPU memory.
+    void ProcessCommandLists(const std::vector<CommandListHeader>& commands);
 
     /// Returns a reference to the Maxwell3D GPU engine.
     Engines::Maxwell3D& Maxwell3D();
@@ -150,14 +134,7 @@ 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.CallMethod({method_address.address, value});
+    maxwell3d.WriteReg(method_address.address, value, 0);
     // Increment the method address by the method increment.
     method_address.address.Assign(method_address.address.Value() +
                                   method_address.increment.Value());

src/video_core/renderer_opengl/gl_rasterizer.cpp

@@ -113,24 +113,10 @@ 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;
@@ -642,7 +628,6 @@ void RasterizerOpenGL::DrawArrays() {
     SyncCullMode();
     SyncPrimitiveRestart();
     SyncScissorTest(state);
-    SyncClipEnabled();
     // Alpha Testing is synced on shaders.
     SyncTransformFeedback();
     SyncPointState();
@@ -1007,28 +992,25 @@ 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];
-        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();
+        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;
+        }
         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() {
-    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;
+    UNREACHABLE();
 }
 
 void RasterizerOpenGL::SyncClipCoef() {

src/video_core/renderer_opengl/gl_rasterizer.h

@@ -189,10 +189,6 @@ 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_shader_manager.h

@@ -60,17 +60,6 @@ public:
     }
 
     void ApplyTo(OpenGLState& state) {
-        UpdatePipeline();
-        state.draw.shader_program = 0;
-        state.draw.program_pipeline = pipeline.handle;
-        state.geometry_shaders.enabled = (gs != 0);
-    }
-
-private:
-    void UpdatePipeline() {
-        // Avoid updating the pipeline when values have no changed
-        if (old_vs == vs && old_fs == fs && old_gs == gs)
-            return;
         // Workaround for AMD bug
         glUseProgramStages(pipeline.handle,
                            GL_VERTEX_SHADER_BIT | GL_GEOMETRY_SHADER_BIT | GL_FRAGMENT_SHADER_BIT,
@@ -79,16 +68,14 @@ private:
         glUseProgramStages(pipeline.handle, GL_VERTEX_SHADER_BIT, vs);
         glUseProgramStages(pipeline.handle, GL_GEOMETRY_SHADER_BIT, gs);
         glUseProgramStages(pipeline.handle, GL_FRAGMENT_SHADER_BIT, fs);
-
-        // Update the old values
-        old_vs = vs;
-        old_fs = fs;
-        old_gs = gs;
+        state.draw.shader_program = 0;
+        state.draw.program_pipeline = pipeline.handle;
+        state.geometry_shaders.enabled = (gs != 0);
     }
 
+private:
     OGLPipeline pipeline;
     GLuint vs{}, fs{}, gs{};
-    GLuint old_vs{}, old_fs{}, old_gs{};
 };
 
 } // namespace OpenGL::GLShader

src/video_core/renderer_opengl/gl_state.cpp

@@ -92,8 +92,7 @@ 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;
@@ -148,7 +147,7 @@ void OpenGLState::ApplyCulling() const {
 }
 
 void OpenGLState::ApplyColorMask() const {
-    if (independant_blend.enabled) {
+    if (GLAD_GL_ARB_viewport_array && 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];
@@ -265,7 +264,7 @@ void OpenGLState::EmulateViewportWithScissor() {
 }
 
 void OpenGLState::ApplyViewport() const {
-    if (geometry_shaders.enabled) {
+    if (GLAD_GL_ARB_viewport_array && geometry_shaders.enabled) {
         for (GLuint i = 0; i < static_cast<GLuint>(Tegra::Engines::Maxwell3D::Regs::NumViewports);
              i++) {
             const auto& current = cur_state.viewports[i];
@@ -526,21 +525,6 @@ 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();
@@ -572,9 +556,11 @@ void OpenGLState::Apply() const {
     if (point.size != cur_state.point.size) {
         glPointSize(point.size);
     }
-    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 (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 (multisample_control.alpha_to_coverage != cur_state.multisample_control.alpha_to_coverage) {
         if (multisample_control.alpha_to_coverage) {
@@ -590,7 +576,7 @@ void OpenGLState::Apply() const {
             glDisable(GL_SAMPLE_ALPHA_TO_ONE);
         }
     }
-    ApplyDepthClamp();
+
     ApplyColorMask();
     ApplyViewport();
     ApplyStencilTest();

src/video_core/renderer_opengl/gl_state.h

@@ -48,11 +48,6 @@ 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;
@@ -190,7 +185,7 @@ public:
         GLfloat clamp;
     } polygon_offset;
 
-    std::array<bool, 8> clip_distance; // GL_CLIP_DISTANCE
+    std::array<bool, 2> clip_distance; // GL_CLIP_DISTANCE
 
     OpenGLState();
 
@@ -240,7 +235,6 @@ private:
     void ApplyLogicOp() const;
     void ApplyTextures() const;
     void ApplySamplers() const;
-    void ApplyDepthClamp() const;
     void ApplyPolygonOffset() const;
 };
 

src/yuzu/configuration/configure_input.cpp

@@ -89,10 +89,6 @@ ConfigureInput::ConfigureInput(QWidget* parent)
 }
 
 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;
     }