Improved error messages in AM, HwOpus and NvMap

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

@@ -616,7 +616,7 @@ private:
 
         const auto storage = applet->GetBroker().PopNormalDataToGame();
         if (storage == nullptr) {
-            LOG_ERROR(Service_AM, "storage is a nullptr");
+            LOG_ERROR(Service_AM, "storage is a nullptr. There is no data in the current channel");
 
             rb.Push(ERR_NO_DATA_IN_CHANNEL);
             return;
@@ -647,7 +647,7 @@ private:
 
         const auto storage = applet->GetBroker().PopInteractiveDataToGame();
         if (storage == nullptr) {
-            LOG_ERROR(Service_AM, "storage is a nullptr");
+            LOG_ERROR(Service_AM, "storage is a nullptr. There is no data in the current channel");
 
             rb.Push(ERR_NO_DATA_IN_CHANNEL);
             return;
@@ -718,7 +718,9 @@ void IStorageAccessor::Write(Kernel::HLERequestContext& ctx) {
     const std::vector<u8> data{ctx.ReadBuffer()};
 
     if (data.size() > backing.buffer.size() - offset) {
-        LOG_ERROR(Service_AM, "offset is out of bounds");
+        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);
@@ -739,7 +741,8 @@ void IStorageAccessor::Read(Kernel::HLERequestContext& ctx) {
     const std::size_t size{ctx.GetWriteBufferSize()};
 
     if (size > backing.buffer.size() - offset) {
-        LOG_ERROR(Service_AM, "offset is out of bounds");
+        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);
@@ -787,7 +790,7 @@ void ILibraryAppletCreator::CreateLibraryApplet(Kernel::HLERequestContext& ctx)
     const auto applet = GetAppletFromId(applet_id);
 
     if (applet == nullptr) {
-        LOG_ERROR(Service_AM, "Applet doesn't exist!");
+        LOG_ERROR(Service_AM, "Applet doesn't exist! applet_id={}", static_cast<u32>(applet_id));
 
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(ResultCode(-1));
@@ -825,7 +828,7 @@ void ILibraryAppletCreator::CreateTransferMemoryStorage(Kernel::HLERequestContex
             handle);
 
     if (shared_mem == nullptr) {
-        LOG_ERROR(Service_AM, "shared_mem is a nullpr");
+        LOG_ERROR(Service_AM, "shared_mem is a nullpr for handle={:08X}", handle);
         IPC::ResponseBuilder rb{ctx, 2};
         rb.Push(ResultCode(-1));
         return;

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

@@ -95,13 +95,15 @@ private:
         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");
+            LOG_ERROR(Audio, "Input is smaller than the header size, header_sz={}, input_sz={}",
+                      sizeof(OpusHeader), input.size());
             return false;
         }
         OpusHeader hdr{};
         std::memcpy(&hdr, input.data(), sizeof(OpusHeader));
         if (sizeof(OpusHeader) + static_cast<u32>(hdr.sz) > input.size()) {
-            LOG_ERROR(Audio, "Input does not fit in the opus header size");
+            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);
@@ -109,14 +111,20 @@ private:
             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");
+            LOG_ERROR(
+                Audio,
+                "Decoded data does not fit into the output data, decoded_sz={}, raw_output_sz={}",
+                decoded_sample_count * channel_count * sizeof(u16), raw_output_sz);
             return false;
         }
+        const int frame_size = (static_cast<int>(raw_output_sz / sizeof(s16) / channel_count));
         auto out_sample_count =
-            opus_decode(decoder.get(), frame, hdr.sz, output.data(),
+            opus_decode(decoder.get(), frame, hdr.sz, output.data(), frame_size, 0);
-                        (static_cast<int>(raw_output_sz / sizeof(s16) / channel_count)), 0);
         if (out_sample_count < 0) {
-            LOG_ERROR(Audio, "Incorrect sample count received from opus_decode");
+            LOG_ERROR(Audio,
+                      "Incorrect sample count received from opus_decode, "
+                      "output_sample_count={}, frame_size={}, data_sz_from_hdr={}",
+                      out_sample_count, frame_size, hdr.sz);
             return false;
         }
         const auto end_time = std::chrono::high_resolution_clock::now() - start_time;
@@ -181,8 +189,8 @@ void HwOpus::OpenOpusDecoder(Kernel::HLERequestContext& ctx) {
     ASSERT_MSG(buffer_sz >= worker_sz, "Worker buffer too large");
     std::unique_ptr<OpusDecoder, OpusDeleter> decoder{
         static_cast<OpusDecoder*>(operator new(worker_sz))};
-    if (opus_decoder_init(decoder.get(), sample_rate, channel_count)) {
+    if (const int err = opus_decoder_init(decoder.get(), sample_rate, channel_count)) {
-        LOG_ERROR(Audio, "Failed to init opus decoder");
+        LOG_ERROR(Audio, "Failed to init opus decoder with error={}", err);
         IPC::ResponseBuilder rb{ctx, 2};
         // TODO(ogniK): Use correct error code
         rb.Push(ResultCode(-1));

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

@@ -79,12 +79,12 @@ u32 nvmap::IocAlloc(const std::vector<u8>& input, std::vector<u8>& output) {
     LOG_DEBUG(Service_NVDRV, "called, addr={:X}", params.addr);
 
     if (!params.handle) {
-        LOG_ERROR(Service_NVDRV, "Handle is zero");
+        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");
+        LOG_ERROR(Service_NVDRV, "Incorrect alignment used, alignment={:08X}", params.align);
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
 
@@ -95,12 +95,12 @@ u32 nvmap::IocAlloc(const std::vector<u8>& input, std::vector<u8>& output) {
 
     auto object = GetObject(params.handle);
     if (!object) {
-        LOG_ERROR(Service_NVDRV, "Object does not exist");
+        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");
+        LOG_ERROR(Service_NVDRV, "Object is already allocated, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::OperationNotPermitted);
     }
 
@@ -127,7 +127,7 @@ u32 nvmap::IocGetId(const std::vector<u8>& input, std::vector<u8>& output) {
 
     auto object = GetObject(params.handle);
     if (!object) {
-        LOG_ERROR(Service_NVDRV, "Object does not exist");
+        LOG_ERROR(Service_NVDRV, "Object does not exist, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::OperationNotPermitted);
     }
 
@@ -146,13 +146,13 @@ u32 nvmap::IocFromId(const std::vector<u8>& input, std::vector<u8>& output) {
     auto itr = std::find_if(handles.begin(), handles.end(),
                             [&](const auto& entry) { return entry.second->id == params.id; });
     if (itr == handles.end()) {
-        LOG_ERROR(Service_NVDRV, "Object does not exist");
+        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");
+        LOG_ERROR(Service_NVDRV, "Object is not allocated, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }
 
@@ -175,12 +175,12 @@ u32 nvmap::IocParam(const std::vector<u8>& input, std::vector<u8>& output) {
 
     auto object = GetObject(params.handle);
     if (!object) {
-        LOG_ERROR(Service_NVDRV, "Object does not exist");
+        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");
+        LOG_ERROR(Service_NVDRV, "Object is not allocated, handle={:08X}", params.handle);
         return static_cast<u32>(NvErrCodes::OperationNotPermitted);
     }
 
@@ -220,12 +220,14 @@ u32 nvmap::IocFree(const std::vector<u8>& input, std::vector<u8>& output) {
 
     auto itr = handles.find(params.handle);
     if (itr == handles.end()) {
-        LOG_ERROR(Service_NVDRV, "Object does not exist");
+        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,
+        LOG_ERROR(
-                  "There is no references to this object. The object is already freed");
+            Service_NVDRV,
+            "There is no references to this object. The object is already freed. handle={:08X}",
+            params.handle);
         return static_cast<u32>(NvErrCodes::InvalidValue);
     }