From ea29fd284ff4bd2a21986378c82ec20e48521c96 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Henrik=20Rydg=C3=A5rd?= Date: Thu, 19 Jun 2025 16:20:13 +0200 Subject: [PATCH] sceAtrac: Logging improvements, constification (and not) --- Core/HLE/AtracCtx.cpp | 20 +++++++++++++++----- Core/HLE/AtracCtx.h | 12 ++++++------ Core/HLE/AtracCtx2.cpp | 23 ++++++++++++++++++++--- Core/HLE/AtracCtx2.h | 6 +++--- Core/HLE/sceAtrac.cpp | 2 +- 5 files changed, 45 insertions(+), 18 deletions(-) diff --git a/Core/HLE/AtracCtx.cpp b/Core/HLE/AtracCtx.cpp index b32011fa11..30673e517d 100644 --- a/Core/HLE/AtracCtx.cpp +++ b/Core/HLE/AtracCtx.cpp @@ -229,7 +229,7 @@ void Track::DebugLog() const { codecType == PSP_CODEC_AT3 ? "AT3" : "AT3Plus", channels, fileSize, bitrate / 1024, jointStereo); DEBUG_LOG(Log::Atrac, "dataoff: %d firstSampleOffset: %d endSample: %d", dataByteOffset, firstSampleOffset, endSample); DEBUG_LOG(Log::Atrac, "loopStartSample: %d loopEndSample: %d", loopStartSample, loopEndSample); - DEBUG_LOG(Log::Atrac, "sampleSize: %d (%03x", bytesPerFrame, bytesPerFrame); + DEBUG_LOG(Log::Atrac, "sampleSize: %d (%03x)", bytesPerFrame, bytesPerFrame); } int Atrac::GetSoundSample(int *endSample, int *loopStartSample, int *loopEndSample) const { @@ -327,7 +327,7 @@ void AtracBase::CreateDecoder(int codecType, int bytesPerFrame, int channels) { } } -int Atrac::GetResetBufferInfo(AtracResetBufferInfo *bufferInfo, int sample, bool *delay) { +int Atrac::GetBufferInfoForResetting(AtracResetBufferInfo *bufferInfo, int sample, bool *delay) { *delay = false; if (BufferState() == ATRAC_STATUS_STREAMED_LOOP_WITH_TRAILER && !HasSecondBuffer()) { return SCE_ERROR_ATRAC_SECOND_BUFFER_NEEDED; @@ -468,9 +468,15 @@ int Atrac::SetData(const Track &track, u32 buffer, u32 readSize, u32 bufferSize, } CreateDecoder(track.codecType, track.bytesPerFrame, track.channels); INFO_LOG(Log::Atrac, "Atrac::SetData (buffer=%08x, readSize=%d, bufferSize=%d): %s %s (%d channels) audio", buffer, readSize, bufferSize, codecName, channelName, track_.channels); + INFO_LOG(Log::Atrac, "BufferState: %s", AtracStatusToString(bufferState_)); + INFO_LOG(Log::Atrac, + "buffer: %08x bufferSize: %d readSize: %d bufferPos: %d\n", + buffer, bufferSize, readSize, bufferPos_ + ); if (track_.channels == 2 && outputChannels == 1) { // We still do all the tasks, we just return this error. + WARN_LOG(Log::Atrac, "Tried to load a stereo track into a mono context, returning NOT_MONO"); return SCE_ERROR_ATRAC_NOT_MONO; } return 0; @@ -494,7 +500,7 @@ int Atrac::SetSecondBuffer(u32 secondBuffer, u32 secondBufferSize) { return 0; } -int Atrac::GetSecondBufferInfo(u32 *fileOffset, u32 *desiredSize) { +int Atrac::GetSecondBufferInfo(u32 *fileOffset, u32 *desiredSize) const { if (BufferState() != ATRAC_STATUS_STREAMED_LOOP_WITH_TRAILER) { // Writes zeroes in this error case. *fileOffset = 0; @@ -715,7 +721,8 @@ u32 Atrac::DecodeData(u8 *outbuf, u32 outbufPtr, int *SamplesNum, int *finish, i // Skip the initial frame used to load state for the looped frame. // TODO: We will want to actually read this in. // TODO again: This seems to happen on the first frame of playback regardless of loops. - // Can't be good. + // Actually, this is explained now if we look at AtracCtx2, although this isn't really accurate. + DEBUG_LOG(Log::Atrac, "Calling ConsumeFrame to skip the initial frame"); ConsumeFrame(); } @@ -723,6 +730,9 @@ u32 Atrac::DecodeData(u8 *outbuf, u32 outbufPtr, int *SamplesNum, int *finish, i bool gotFrame = false; u32 off = track_.FileOffsetBySample(currentSample_ - skipSamples); + + DEBUG_LOG(Log::Atrac, "Decode(%08x): nextFileOff: %d", outbufPtr, off); + if (off < first_.size) { uint8_t *indata = BufferStart() + off; int bytesConsumed = 0; @@ -846,7 +856,7 @@ int Atrac::ResetPlayPosition(int sample, int bytesWrittenFirstBuf, int bytesWrit // Reuse the same calculation as before. AtracResetBufferInfo bufferInfo; bool ignored; - GetResetBufferInfo(&bufferInfo, sample, &ignored); + GetBufferInfoForResetting(&bufferInfo, sample, &ignored); if ((u32)bytesWrittenFirstBuf < bufferInfo.first.minWriteBytes || (u32)bytesWrittenFirstBuf > bufferInfo.first.writableBytes) { return SCE_ERROR_ATRAC_BAD_FIRST_RESET_SIZE; diff --git a/Core/HLE/AtracCtx.h b/Core/HLE/AtracCtx.h index 276fd38a90..75fa627af1 100644 --- a/Core/HLE/AtracCtx.h +++ b/Core/HLE/AtracCtx.h @@ -124,18 +124,18 @@ public: virtual int BytesPerFrame() const = 0; virtual int SamplesPerFrame() const = 0; - virtual void GetStreamDataInfo(u32 *writePtr, u32 *writableBytes, u32 *readOffset) = 0; + virtual void GetStreamDataInfo(u32 *writePtr, u32 *writableBytes, u32 *readOffset) = 0; // This should be const, but the legacy impl stops it (it's wrong). virtual int AddStreamData(u32 bytesToAdd) = 0; virtual int ResetPlayPosition(int sample, int bytesWrittenFirstBuf, int bytesWrittenSecondBuf, bool *delay) = 0; - virtual int GetResetBufferInfo(AtracResetBufferInfo *bufferInfo, int sample, bool *delay) = 0; + virtual int GetBufferInfoForResetting(AtracResetBufferInfo *bufferInfo, int sample, bool *delay) = 0; // NOTE: Not const! This can cause SkipFrames! virtual int SetData(const Track &track, u32 buffer, u32 readSize, u32 bufferSize, int outputChannels) = 0; - virtual int GetSecondBufferInfo(u32 *fileOffset, u32 *desiredSize) = 0; + virtual int GetSecondBufferInfo(u32 *fileOffset, u32 *desiredSize) const = 0; virtual int SetSecondBuffer(u32 secondBuffer, u32 secondBufferSize) = 0; virtual u32 DecodeData(u8 *outbuf, u32 outbufPtr, int *SamplesNum, int *finish, int *remains) = 0; virtual int DecodeLowLevel(const u8 *srcData, int *bytesConsumed, s16 *dstData, int *bytesWritten) = 0; - virtual u32 GetNextSamples() = 0; + virtual u32 GetNextSamples() = 0; // This should be const, but the legacy impl stops it (it's wrong). virtual void InitLowLevel(const Atrac3LowLevelParams ¶ms, int codecType) = 0; virtual void CheckForSas() = 0; @@ -224,9 +224,9 @@ public: // Notify the player that the user has written some new data. int AddStreamData(u32 bytesToAdd) override; int ResetPlayPosition(int sample, int bytesWrittenFirstBuf, int bytesWrittenSecondBuf, bool *delay) override; - int GetResetBufferInfo(AtracResetBufferInfo *bufferInfo, int sample, bool *delay) override; + int GetBufferInfoForResetting(AtracResetBufferInfo *bufferInfo, int sample, bool *delay) override; // NOTE: Not const! This can cause SkipFrames! (although only in the AtracCtx2) int SetData(const Track &track, u32 buffer, u32 readSize, u32 bufferSize, int outputChannels) override; - int GetSecondBufferInfo(u32 *fileOffset, u32 *desiredSize) override; + int GetSecondBufferInfo(u32 *fileOffset, u32 *desiredSize) const override; int SetSecondBuffer(u32 secondBuffer, u32 secondBufferSize) override; u32 DecodeData(u8 *outbuf, u32 outbufPtr, int *SamplesNum, int *finish, int *remains) override; int DecodeLowLevel(const u8 *srcData, int *bytesConsumed, s16 *dstData, int *bytesWritten) override; diff --git a/Core/HLE/AtracCtx2.cpp b/Core/HLE/AtracCtx2.cpp index 467e24b1fd..8ee036055b 100644 --- a/Core/HLE/AtracCtx2.cpp +++ b/Core/HLE/AtracCtx2.cpp @@ -331,7 +331,8 @@ u32 Atrac2::ResetPlayPositionInternal(int seekPos, int bytesWrittenFirstBuf, int } // This is basically sceAtracGetBufferInfoForResetting. -int Atrac2::GetResetBufferInfo(AtracResetBufferInfo *bufferInfo, int seekPos, bool *delay) { +// NOTE: Not const! This can cause SkipFrames! +int Atrac2::GetBufferInfoForResetting(AtracResetBufferInfo *bufferInfo, int seekPos, bool *delay) { const SceAtracIdInfo &info = context_->info; if (info.state == ATRAC_STATUS_STREAMED_LOOP_WITH_TRAILER && info.secondBufferByte == 0) { @@ -354,7 +355,7 @@ int Atrac2::GetResetBufferInfo(AtracResetBufferInfo *bufferInfo, int seekPos, bo return retval; } -void Atrac2::GetResetBufferInfoInternal(AtracResetBufferInfo *bufferInfo, int seekPos) { +void Atrac2::GetResetBufferInfoInternal(AtracResetBufferInfo *bufferInfo, int seekPos) const { const SceAtracIdInfo &info = context_->info; switch (info.state) { @@ -666,6 +667,8 @@ u32 Atrac2::DecodeInternal(u32 outbufAddr, int *SamplesNum, int *finish) { return SCE_ERROR_ATRAC_ALL_DATA_DECODED; } + DEBUG_LOG(Log::Atrac, "Decode(%08x): samplesToDecode: %d nextFileOff: %d", outbufAddr, samplesToDecode, nextFileOff); + // Check for streaming buffer run-out. if (AtracStatusIsStreaming(info.state) && info.streamDataByte < info.sampleSize) { *finish = 0; @@ -899,6 +902,17 @@ int Atrac2::SetData(const Track &track, u32 bufferAddr, u32 readSize, u32 buffer info.numSkipFrames = info.firstValidSample / info.SamplesPerFrame(); // NOTE: we do not write into secondBuffer/secondBufferByte! they linger... + INFO_LOG(Log::Atrac, + "Atrac: sampleSize: %d buffer: %08x bufferByte: %d firstValidSample: %d\n" + "endSample: %d loopStart: %d loopEnd: %d\n" + "dataOff: %d curFileOff: %d streamOff: %d streamDataByte: %d\n" + "fileDataEnd: %d decodePos: %d numSkipFrames: %d", + info.sampleSize, info.buffer, info.bufferByte, info.firstValidSample, + info.endSample, info.loopStart, info.loopEnd, + info.dataOff, info.curFileOff, info.streamOff, info.streamDataByte, + info.fileDataEnd, info.decodePos, info.numSkipFrames + ); + int skipCount = 0; // TODO: use for delay u32 retval = SkipFrames(&skipCount); @@ -949,9 +963,12 @@ u32 Atrac2::SkipFrames(int *skipCount) { u32 retval = DecodeInternal(0, 0, &finishIgnored); if (retval != 0) { if (retval == SCE_ERROR_ATRAC_API_FAIL) { + WARN_LOG(Log::Atrac, "Failed during skip-frame, ignoring: %08x", retval); (*skipCount)++; } return retval; + } else { + DEBUG_LOG(Log::Atrac, "Frame correctly decoded during skip. numSkipFrames == %d", info.numSkipFrames); } (*skipCount)++; } @@ -959,7 +976,7 @@ u32 Atrac2::SkipFrames(int *skipCount) { } // Where to read from to fill the second buffer. -int Atrac2::GetSecondBufferInfo(u32 *fileOffset, u32 *readSize) { +int Atrac2::GetSecondBufferInfo(u32 *fileOffset, u32 *readSize) const { const SceAtracIdInfo &info = context_->info; if (info.state != ATRAC_STATUS_STREAMED_LOOP_WITH_TRAILER) { // No second buffer needed in this state. diff --git a/Core/HLE/AtracCtx2.h b/Core/HLE/AtracCtx2.h index 2a5554df66..a882b62cf2 100644 --- a/Core/HLE/AtracCtx2.h +++ b/Core/HLE/AtracCtx2.h @@ -31,10 +31,10 @@ public: int CodecType() const override { return context_->info.codec; } void GetStreamDataInfo(u32 *writePtr, u32 *writableBytes, u32 *readOffset) override; - int GetSecondBufferInfo(u32 *fileOffset, u32 *desiredSize) override; + int GetSecondBufferInfo(u32 *fileOffset, u32 *desiredSize) const override; int AddStreamData(u32 bytesToAdd) override; int ResetPlayPosition(int sample, int bytesWrittenFirstBuf, int bytesWrittenSecondBuf, bool *delay) override; - int GetResetBufferInfo(AtracResetBufferInfo *bufferInfo, int sample, bool *delay) override; + int GetBufferInfoForResetting(AtracResetBufferInfo *bufferInfo, int sample, bool *delay) override; int SetData(const Track &track, u32 buffer, u32 readSize, u32 bufferSize, int outputChannels) override; int SetSecondBuffer(u32 secondBuffer, u32 secondBufferSize) override; bool HasSecondBuffer() const override; @@ -62,7 +62,7 @@ public: private: u32 DecodeInternal(u32 outbufAddr, int *SamplesNum, int *finish); - void GetResetBufferInfoInternal(AtracResetBufferInfo *bufferInfo, int sample); + void GetResetBufferInfoInternal(AtracResetBufferInfo *bufferInfo, int sample) const; u32 ResetPlayPositionInternal(int seekPos, int bytesWrittenFirstBuf, int bytesWrittenSecondBuf); u32 SkipFrames(int *skippedCount); diff --git a/Core/HLE/sceAtrac.cpp b/Core/HLE/sceAtrac.cpp index 2cabb0acb3..1fafd0b614 100644 --- a/Core/HLE/sceAtrac.cpp +++ b/Core/HLE/sceAtrac.cpp @@ -385,7 +385,7 @@ static u32 sceAtracGetBufferInfoForResetting(int atracID, int sample, u32 buffer // Note: If we error here, it's because of the internal SkipFrames. // We delayresult if we skip frames, which indeed can happen. bool delay = false; - int ret = atrac->GetResetBufferInfo(bufferInfo, sample, &delay); + int ret = atrac->GetBufferInfoForResetting(bufferInfo, sample, &delay); if (delay) { return hleDelayResult(hleLogDebugOrError(Log::Atrac, ret), "getreset_frameskip", 300); } else {