From 3d627df4d8a682d39e94116b0fc094b752d8d49f Mon Sep 17 00:00:00 2001 From: David Marcec Date: Mon, 26 Nov 2018 20:05:09 +1100 Subject: [PATCH] Improved error messages in AM, HwOpus and NvMap --- src/core/hle/service/am/am.cpp | 15 ++++++----- src/core/hle/service/audio/hwopus.cpp | 24 ++++++++++++------ src/core/hle/service/nvdrv/devices/nvmap.cpp | 26 +++++++++++--------- 3 files changed, 39 insertions(+), 26 deletions(-) diff --git a/src/core/hle/service/am/am.cpp b/src/core/hle/service/am/am.cpp index 0bd52b602e..f6757adab6 100644 --- a/src/core/hle/service/am/am.cpp +++ b/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 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(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; diff --git a/src/core/hle/service/audio/hwopus.cpp b/src/core/hle/service/audio/hwopus.cpp index 832159394c..5e3672dbd9 100644 --- a/src/core/hle/service/audio/hwopus.cpp +++ b/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(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(hdr.sz), input.size()); return false; } auto frame = input.data() + sizeof(OpusHeader); @@ -109,14 +111,20 @@ private: frame, static_cast(input.size() - sizeof(OpusHeader)), static_cast(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(raw_output_sz / sizeof(s16) / channel_count)); auto out_sample_count = - opus_decode(decoder.get(), frame, hdr.sz, output.data(), - (static_cast(raw_output_sz / sizeof(s16) / channel_count)), 0); + opus_decode(decoder.get(), frame, hdr.sz, output.data(), frame_size, 0); if (out_sample_count < 0) { - LOG_ERROR(Audio, "Incorrect sample count received from opus_decode"); + 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 decoder{ static_cast(operator new(worker_sz))}; - if (opus_decoder_init(decoder.get(), sample_rate, channel_count)) { - LOG_ERROR(Audio, "Failed to init opus decoder"); + if (const int err = opus_decoder_init(decoder.get(), sample_rate, channel_count)) { + LOG_ERROR(Audio, "Failed to init opus decoder with error={}", err); IPC::ResponseBuilder rb{ctx, 2}; // TODO(ogniK): Use correct error code rb.Push(ResultCode(-1)); diff --git a/src/core/hle/service/nvdrv/devices/nvmap.cpp b/src/core/hle/service/nvdrv/devices/nvmap.cpp index 85ba5d4b78..1ec796fc6d 100644 --- a/src/core/hle/service/nvdrv/devices/nvmap.cpp +++ b/src/core/hle/service/nvdrv/devices/nvmap.cpp @@ -79,12 +79,12 @@ u32 nvmap::IocAlloc(const std::vector& input, std::vector& 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(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(NvErrCodes::InvalidValue); } @@ -95,12 +95,12 @@ u32 nvmap::IocAlloc(const std::vector& input, std::vector& 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(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(NvErrCodes::OperationNotPermitted); } @@ -127,7 +127,7 @@ u32 nvmap::IocGetId(const std::vector& input, std::vector& 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(NvErrCodes::OperationNotPermitted); } @@ -146,13 +146,13 @@ u32 nvmap::IocFromId(const std::vector& input, std::vector& 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(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(NvErrCodes::InvalidValue); } @@ -175,12 +175,12 @@ u32 nvmap::IocParam(const std::vector& input, std::vector& 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(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(NvErrCodes::OperationNotPermitted); } @@ -220,12 +220,14 @@ u32 nvmap::IocFree(const std::vector& input, std::vector& 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(NvErrCodes::InvalidValue); } if (!itr->second->refcount) { - LOG_ERROR(Service_NVDRV, - "There is no references to this object. The object is already freed"); + LOG_ERROR( + Service_NVDRV, + "There is no references to this object. The object is already freed. handle={:08X}", + params.handle); return static_cast(NvErrCodes::InvalidValue); }