hrydgard / ppsspp

A PSP emulator for Android, Windows, Mac and Linux, written in C++. Want to contribute? Join us on Discord at https://discord.gg/5NJB6dD or just send pull requests / issues. For discussion use the forums at forums.ppsspp.org.
https://www.ppsspp.org
Other
11.25k stars 2.17k forks source link

bug in SimpleAudio::Decode ffmpeg logic #18895

Open rofl0r opened 8 months ago

rofl0r commented 8 months ago

Game or games this happens in

homebrew using mp3 api

What area of the game / PPSSPP

N/A

What should happen

according to https://ffmpeg.org/doxygen/trunk/group__lavc__decoding.html#ga58bc4bf1e0ac59e27362597e467efff3 avcodec_send_packet() has a 1:n relation to avcodec_receive_frame()

it states:

the packet is always fully consumed, and if it contains multiple frames (e.g. some audio codecs), will require you to call avcodec_receive_frame() multiple times afterwards before you can send a new packet

currently the code sends one packet, then receives one frame, which is wrong. i noticed this because PPSSPP kept spamming the terminal about EAGAIN received from avcodec_send_packet instead of playing music from the pspsdk mp3 sample code.

here's a patch that does the conceptually right thing: drain ffmpeg of all frames after sending a packet. however, after applying it i now get

36:15:781 user_main    E[SCEAUDIO]: HLE/__sceAudio.cpp:360 Channel 8 buffer underrun at 32 of 64
36:15:873 user_main    E[SCEAUDIO]: HLE/__sceAudio.cpp:360 Channel 8 buffer underrun at 16 of 64
36:15:873 user_main    E[ME]: HW/SimpleAudioDec.cpp:268 Error decoding Audio frame (14776 bytes): -1094995529 (bebbb1b7)
36:16:089 user_main    E[ME]: HW/SimpleAudioDec.cpp:249 Error sending audio frame to decoder (14632 bytes): -1094995529 (bebbb1b7)

and i'm lacking the nerve to further debug/fix the issue.

patch:

diff --git a/Core/HW/SimpleAudioDec.cpp b/Core/HW/SimpleAudioDec.cpp
index 80397bf6d..50aa66fe8 100644
--- a/Core/HW/SimpleAudioDec.cpp
+++ b/Core/HW/SimpleAudioDec.cpp
@@ -179,7 +179,55 @@ bool SimpleAudio::IsOK() const {
 #endif
 }

+#ifdef USE_FFMPEG
+bool SimpleAudio::ProcessFrame(uint8_t **outbuf, int *outbytes) {
+   // Initializing the sample rate convert. We will use it to convert float output into int.
+   int64_t wanted_channel_layout = AV_CH_LAYOUT_STEREO; // we want stereo output layout
+   int64_t dec_channel_layout = frame_->channel_layout; // decoded channel layout
+
+   if (!swrCtx_) {
+       swrCtx_ = swr_alloc_set_opts(
+           swrCtx_,
+           wanted_channel_layout,
+           AV_SAMPLE_FMT_S16,
+           wanted_resample_freq,
+           dec_channel_layout,
+           codecCtx_->sample_fmt,
+           codecCtx_->sample_rate,
+           0,
+           NULL);
+
+       if (!swrCtx_ || swr_init(swrCtx_) < 0) {
+           ERROR_LOG(ME, "swr_init: Failed to initialize the resampling context");
+           avcodec_close(codecCtx_);
+           codec_ = 0;
+           return false;
+       }
+   }
+
+   // convert audio to AV_SAMPLE_FMT_S16
+   int swrRet = 0;
+   if (*outbuf != nullptr) {
+       swrRet = swr_convert(swrCtx_, &(*outbuf), frame_->nb_samples, (const u8 **)frame_->extended_data, frame_->nb_samples);
+   }
+   if (swrRet < 0) {
+       ERROR_LOG(ME, "swr_convert: Error while converting: %d", swrRet);
+       return false;
+   }
+   // output samples per frame, we should *2 since we have two channels
+   outSamples = swrRet * 2;
+   // each sample occupies 2 bytes
+   *outbytes += outSamples * 2;
+   *outbuf += outSamples * 2;
+
+   // Save outbuf into pcm audio, you can uncomment this line to save and check the decoded audio into pcm file.
+   // SaveAudio("dump.pcm", outbuf, *outbytes);
+   return true;
+}
+#endif
+
 bool SimpleAudio::Decode(const uint8_t *inbuf, int inbytes, uint8_t *outbuf, int *outbytes) {
+   bool ret = true;
 #ifdef USE_FFMPEG
    if (!codecOpen_) {
        OpenCodec(inbytes);
@@ -196,82 +244,49 @@ bool SimpleAudio::Decode(const uint8_t *inbuf, int inbytes, uint8_t *outbuf, int
    *outbytes = 0;
    srcPos = 0;
 #if LIBAVCODEC_VERSION_INT >= AV_VERSION_INT(57, 48, 101)
+   int err = 0;
    if (inbytes != 0) {
        int err = avcodec_send_packet(codecCtx_, &packet);
-       if (err < 0) {
+       if (err < 0 && err != AVERROR(EAGAIN)) {
            ERROR_LOG(ME, "Error sending audio frame to decoder (%d bytes): %d (%08x)", inbytes, err, err);
            return false;
        }
    }
-   int err = avcodec_receive_frame(codecCtx_, frame_);
-   int len = 0;
-   if (err >= 0) {
-       len = frame_->pkt_size;
-       got_frame = 1;
-   } else if (err != AVERROR(EAGAIN)) {
-       len = err;
-   }
+   while(1) {
+       int err = avcodec_receive_frame(codecCtx_, frame_);
+       int len = 0;
+       if (err == AVERROR(EAGAIN) || err == AVERROR_EOF)
+           break;
+       if (err >= 0) {
+           len = frame_->pkt_size;
+           got_frame = 1;
+       } else if (err != AVERROR(EAGAIN)) {
+           len = err;
+       }
 #else
-   int len = avcodec_decode_audio4(codecCtx_, frame_, &got_frame, &packet);
+       int len = avcodec_decode_audio4(codecCtx_, frame_, &got_frame, &packet);
 #endif
+       if (len < 0) {
+           ERROR_LOG(ME, "Error decoding Audio frame (%i bytes): %i (%08x)", inbytes, len, len);
+           ret = false;
+           break;
+       }
+       // get bytes consumed in source
+       if(len > 0 && !srcPos) {
+           srcPos = len;
+       }
+
+       if (got_frame) {
+           if(!ProcessFrame(&outbuf, outbytes)) break;
+       }
+   }
+
 #if LIBAVCODEC_VERSION_INT >= AV_VERSION_INT(57, 12, 100)
    av_packet_unref(&packet);
 #else
    av_free_packet(&packet);
 #endif
-
-   if (len < 0) {
-       ERROR_LOG(ME, "Error decoding Audio frame (%i bytes): %i (%08x)", inbytes, len, len);
-       return false;
-   }
-   
-   // get bytes consumed in source
-   srcPos = len;
-
-   if (got_frame) {
-       // Initializing the sample rate convert. We will use it to convert float output into int.
-       int64_t wanted_channel_layout = AV_CH_LAYOUT_STEREO; // we want stereo output layout
-       int64_t dec_channel_layout = frame_->channel_layout; // decoded channel layout
-
-       if (!swrCtx_) {
-           swrCtx_ = swr_alloc_set_opts(
-               swrCtx_,
-               wanted_channel_layout,
-               AV_SAMPLE_FMT_S16,
-               wanted_resample_freq,
-               dec_channel_layout,
-               codecCtx_->sample_fmt,
-               codecCtx_->sample_rate,
-               0,
-               NULL);
-
-           if (!swrCtx_ || swr_init(swrCtx_) < 0) {
-               ERROR_LOG(ME, "swr_init: Failed to initialize the resampling context");
-               avcodec_close(codecCtx_);
-               codec_ = 0;
-               return false;
-           }
-       }
-
-       // convert audio to AV_SAMPLE_FMT_S16
-       int swrRet = 0;
-       if (outbuf != nullptr) {
-           swrRet = swr_convert(swrCtx_, &outbuf, frame_->nb_samples, (const u8 **)frame_->extended_data, frame_->nb_samples);
-       }
-       if (swrRet < 0) {
-           ERROR_LOG(ME, "swr_convert: Error while converting: %d", swrRet);
-           return false;
-       }
-       // output samples per frame, we should *2 since we have two channels
-       outSamples = swrRet * 2;
-
-       // each sample occupies 2 bytes
-       *outbytes = outSamples * 2;
-
-       // Save outbuf into pcm audio, you can uncomment this line to save and check the decoded audio into pcm file.
-       // SaveAudio("dump.pcm", outbuf, *outbytes);
-   }
-   return true;
+   return ret;
 #else
    // Zero bytes output. No need to memset.
    *outbytes = 0;
diff --git a/Core/HW/SimpleAudioDec.h b/Core/HW/SimpleAudioDec.h
index 9bf2427a4..18083526c 100644
--- a/Core/HW/SimpleAudioDec.h
+++ b/Core/HW/SimpleAudioDec.h
@@ -94,6 +94,9 @@ class SimpleAudio {
    SwrContext      *swrCtx_;

    bool codecOpen_;
+#ifdef USE_FFMPEG
+   bool ProcessFrame(uint8_t **outbuf, int *outbytes);
+#endif
 };

 void AudioClose(SimpleAudio **ctx);

my ffmpeg version is ffmpeg-4.3.5

Logs

No response

Platform

Linux / BSD

Mobile device model or graphics card (GPU)

n/a

PPSSPP version affected

git

Last working version

n/a

Graphics backend (3D API)

OpenGL / GLES

Checklist

rofl0r commented 8 months ago

here's my code to trigger the bug:

/*
 * PSP Software Development Kit - https://github.com/pspdev
 * -----------------------------------------------------------------------
 * Licensed under the BSD license, see LICENSE in PSPSDK root for details.
 *
 * main.c - Sample to demonstrate proper use of the mp3 library
 *
 * Copyright (c) 2008 Alexander Berl <raphael@fx-world.org>
 *
 */
#include <pspkernel.h>
#include <pspdebug.h>
#include <pspctrl.h>
#include <pspdisplay.h>
#include <stdio.h>
#include <pspaudio.h>
#include <pspmp3.h>
#include <psputility.h>
#include <string.h>

/* Define the module info section */
PSP_MODULE_INFO("Mp3Test", 0, 0, 1);
PSP_MAIN_THREAD_ATTR(THREAD_ATTR_USER);
PSP_HEAP_SIZE_KB(-1024);

#define MP3FILE "ms0:/MUSIC/test.mp3"

// Input and Output buffers
unsigned char mp3Buf[16 * 1024] __attribute__ ((aligned(64)));
unsigned short pcmBuf[16 * (1152 / 2)] __attribute__ ((aligned(64)));

/* Define printf, just to make typing easier */
#define printf  pspDebugScreenPrintf

static int isrunning = 1;
/* Exit callback */
int exit_callback(int arg1, int arg2, void *common)
{
    isrunning = 0;
    return 0;
}

/* Callback thread */
int CallbackThread(SceSize args, void *argp)
{
    int cbid;
    cbid = sceKernelCreateCallback("Exit Callback", exit_callback, NULL);
    sceKernelRegisterExitCallback(cbid);
    sceKernelSleepThreadCB();
    return 0;
}

/* Sets up the callback thread and returns its thread id */
int SetupCallbacks(void)
{
    int thid = 0;
    thid =
        sceKernelCreateThread("update_thread", CallbackThread, 0x11, 0xFA0,
                  0, 0);
    if (thid >= 0)
        sceKernelStartThread(thid, 0, 0);
    return thid;
}

// Macro to allow formatted input without having to use stdargs.h
#define ERRORMSG(...) { char msg[128]; sprintf(msg,__VA_ARGS__); error(msg); }

// Print out an error message and quit after user input
void error(char *msg)
{
    SceCtrlData pad;
    pspDebugScreenClear();
    pspDebugScreenSetXY(0, 0);
    printf(msg);
    printf("Press X to quit.\n");
    while (isrunning) {
        sceCtrlReadBufferPositive(&pad, 1);
        if (pad.Buttons & PSP_CTRL_CROSS)
            break;
        sceDisplayWaitVblankStart();
    }
    sceKernelExitGame();
}

int fillStreamBuffer(int fd, int handle)
{
    char *dst;
    int towrite, nread, pos;
    // Get Info on the stream (where to fill to, how much to fill, where to fill from)
    int status = sceMp3GetInfoToAddStreamData(handle, &dst, &towrite, &pos);
    if (status < 0) {
        ERRORMSG
            ("ERROR: sceMp3GetInfoToAddStreamData returned 0x%08X\n",
             status);
    }
    // Seek file to position requested
    status = sceIoLseek32(fd, pos, SEEK_SET);
    if (status < 0) {
        ERRORMSG("ERROR: sceIoLseek32 returned 0x%08X\n", status);
    }
    // Read the amount of data
    nread = sceIoRead(fd, dst, towrite);
    if (nread < 0) {
        ERRORMSG("ERROR: Could not read from file - 0x%08X\n", nread);
    }

    if (nread == 0) {
        // End of file?
        return 0;
    }
    // Notify mp3 library about how much we really wrote to the stream buffer
    status = sceMp3NotifyAddStreamData(handle, nread);
    if (status < 0) {
        ERRORMSG("ERROR: sceMp3NotifyAddStreamData returned 0x%08X\n",
             status);
    }

    return (pos > 0);
}

// skip ID3 header.
static int find_mp3_frame(int fd) {
    int status, start = 0;
    unsigned char buf[4096];
    status = sceIoRead(fd, buf, sizeof(buf));
    if(status >= 3 && buf[0] == 'I' && buf[1] == 'D' && buf[2] == '3') {
        while(1) {
            int i, lastff = 0;
            for(i = 0; i < status; ++i) {
                if(lastff) {
                    if(buf[i] & 0xf0) {
                        start += i-1;
                        goto frame_found;
                    }
                    lastff = 0;
                }
                if(buf[i] == 0xff) lastff = 1;
            }
            start += status;
            status = sceIoRead(fd, buf, sizeof(buf));
            if(status <= 0) ERRORMSG("ERROR: couldnt find mp3 header\n");
        }
frame_found:;
#if 0
        if(status >= 10 && buf[3] == 3 && buf[4] == 0) /* id3 v2.3 */
            start = (buf[6] << 21) | (buf[7] << 14) |
                (buf[8] << 7)  | buf[9];
#endif
    }
    return start;
}

static int load_file(char *fn, int* fd, int *handle, SceMp3InitArg *arg)
{
    int status, start;
    unsigned char buf[4096];
    // Open the input file
    *fd = sceIoOpen(fn, PSP_O_RDONLY, 0777);
    if (*fd < 0) {
        ERRORMSG("ERROR: Could not open file '%s' - 0x%08X\n", fn, *fd);
    }

    start = find_mp3_frame(*fd);

    // Init mp3 resources
    status = sceMp3InitResource();
    if (status < 0) {
        ERRORMSG("ERROR: sceMp3InitResource returned 0x%08X\n", status);
    }

    memset(arg, 0, sizeof(*arg));
    arg->mp3StreamStart = start;
    arg->mp3StreamEnd = sceIoLseek32(*fd, 0, SEEK_END);
    arg->mp3Buf = mp3Buf;
    arg->mp3BufSize = sizeof(mp3Buf);
    arg->pcmBuf = pcmBuf;
    arg->pcmBufSize = sizeof(pcmBuf);

    *handle = sceMp3ReserveMp3Handle(arg);
    if (*handle < 0) {
        ERRORMSG("ERROR: sceMp3ReserveMp3Handle returned 0x%08X\n",
             *handle);
    }

    // Fill the stream buffer with some data so that sceMp3Init has something to work with
    fillStreamBuffer(*fd, *handle);

    status = sceMp3Init(*handle);
    if (status < 0) {
        ERRORMSG("ERROR: sceMp3Init returned 0x%08X\n", status);
    }

    return status;
}

#define DECODE_MAGIC 0x80671402
//#define DECODE_MAGIC 0x80671103

int main(int argc, char *argv[])
{
    SceCtrlData pad;
    int status, handle, fd;
    SceMp3InitArg mp3Init;

    //init screen and callbacks
    pspDebugScreenInit();
    pspDebugScreenClear();
    SetupCallbacks();

    // Setup Pad
    sceCtrlSetSamplingCycle(0);
    sceCtrlSetSamplingMode(0);

    // Load modules
    status = sceUtilityLoadModule(PSP_MODULE_AV_AVCODEC);
    //status = sceUtilityLoadAvModule(PSP_AV_MODULE_AVCODEC);
    if (status < 0) {
        ERRORMSG
            ("ERROR: sceUtilityLoadModule(PSP_MODULE_AV_AVCODEC) returned 0x%08X\n",
             status);
    }

    status = sceUtilityLoadModule(PSP_MODULE_AV_MP3);
    //status = sceUtilityLoadAvModule(PSP_AV_MODULE_MP3);
    if (status < 0) {
        ERRORMSG
            ("ERROR: sceUtilityLoadModule(PSP_MODULE_AV_MP3) returned 0x%08X\n",
             status);
    }

#if 0
    status = sceAudioInit();
    if (status < 0) {
        ERRORMSG
            ("ERROR: sceAudioInit() returned 0x%08X\n",
             status);
    }
#endif

    // Reserve a mp3 handle for our playback

    load_file(MP3FILE, &fd, &handle, &mp3Init);

    int channel = -1;
    int samplingRate = sceMp3GetSamplingRate(handle);
    int numChannels = sceMp3GetMp3ChannelNum(handle);
    int volume = 0x7000; //PSP_AUDIO_VOLUME_MAX;
    int numPlayed = 0;
    int paused = 0;
    int lastButtons = 0;
    int loop = 0;

    while (isrunning) {
        sceDisplayWaitVblankStart();
        pspDebugScreenSetXY(0, 0);
        printf("PSP Mp3 Sample v1.0 by Raphael\n\n");
        printf("Playing '%s'...\n", MP3FILE);
        printf(" %i Hz\n", samplingRate);
        printf(" %i kbit/s\n", sceMp3GetBitRate(handle));
        printf(" %s\n", numChannels == 2 ? "Stereo" : "Mono");
        printf(" %s\n\n", loop == 0 ? "No loop" : "Loop");
        int playTime = samplingRate > 0 ? numPlayed / samplingRate : 0;
        printf(" Playtime: %02i:%02i\n", playTime / 60, playTime % 60);
        printf
            ("\n\n\nPress CIRCLE to Pause/Resume playback\nPress TRIANGLE to reset playback\nPress CROSS to switch loop mode\nPress SQUARE to stop playback and quit\n");

        if (!paused) {
            // Check if we need to fill our stream buffer
            if (sceMp3CheckStreamDataNeeded(handle) > 0) {
                fillStreamBuffer(fd, handle);
            }
            // Decode some samples
            short *buf;
            int bytesDecoded;
            int retries = 0;
            // We retry in case it's just that we reached the end of the stream and need to loop
            for (; retries < 1; retries++) {
                bytesDecoded = sceMp3Decode(handle, &buf);
                if (bytesDecoded > 0)
                    break;

                if (sceMp3CheckStreamDataNeeded(handle) <= 0)
                    break;

                if (!fillStreamBuffer(fd, handle)) {
                    numPlayed = 0;
                }
            }
            if (bytesDecoded < 0 && bytesDecoded != DECODE_MAGIC) {
                ERRORMSG
                    ("ERROR: sceMp3Decode returned 0x%08X\n",
                     bytesDecoded);
            }
            // Nothing more to decode? Must have reached end of input buffer
            if (bytesDecoded == 0 || bytesDecoded == DECODE_MAGIC) {
                paused = 1;
                sceMp3ResetPlayPosition(handle);
                numPlayed = 0;
            } else while(bytesDecoded > 0) {
                int samples = bytesDecoded / (2 * numChannels);
                /* PPSSPP limits the range of SRC channel reservation samples to 17 - 4111. */
                int actualSamples = samples > 4032 ? 4032 : samples;
                samples -= actualSamples;
                if (samples <= 17) actualSamples += samples;

                // Reserve the Audio channel for our output if not yet done
                if (channel >= 0) {
                    while(sceAudioOutput2GetRestSample()) ;
                    while(0x80268002 == sceAudioSRCChRelease()); /* loop until not busy */
                    channel = -1;
                }

                if (channel < 0) {
                    // samplingRate,
                    channel = sceAudioSRCChReserve(
                          actualSamples,
                          samplingRate,
                          numChannels);
                }
                // Output the decoded samples and accumulate the number of played samples to get the playtime
                numPlayed +=
                    sceAudioSRCOutputBlocking(volume, buf);

                buf += numPlayed;
                bytesDecoded -= (numPlayed*2);
            }
        }

        sceCtrlPeekBufferPositive(&pad, 1);

        if (pad.Buttons != lastButtons) {
            if (pad.Buttons & PSP_CTRL_CIRCLE) {
                paused ^= 1;
            }

            if (pad.Buttons & PSP_CTRL_TRIANGLE) {
                // Reset the stream and playback status
                sceMp3ResetPlayPosition(handle);
                numPlayed = 0;
            }

            if (pad.Buttons & PSP_CTRL_CROSS) {
                loop = (loop == 0 ? -1 : 0);
                status = sceMp3SetLoopNum(handle, loop);
                if (status < 0) {
                    ERRORMSG
                        ("ERROR: sceMp3SetLoopNum returned 0x%08X\n",
                         status);
                }
            }

            if (pad.Buttons & PSP_CTRL_SQUARE) {
                break;
            }

            lastButtons = pad.Buttons;
        }
    }

    // Cleanup time...
    if (channel >= 0)
        sceAudioChRelease(channel);

    status = sceMp3ReleaseMp3Handle(handle);
    if (status < 0) {
        ERRORMSG("ERROR: sceMp3ReleaseMp3Handle returned 0x%08X\n",
             status);
    }

    status = sceMp3TermResource();
    if (status < 0) {
        ERRORMSG("ERROR: sceMp3TermResource returned 0x%08X\n", status);
    }

    status = sceIoClose(fd);
    if (status < 0) {
        ERRORMSG("ERROR: sceIoClose returned 0x%08X\n", status);
    }

    sceKernelExitGame();

    return 0;
}

makefile:

TARGET = All
OBJS = main.o

CFLAGS = -O2 -G0 -Wall
CXXFLAGS = $(CFLAGS) -fno-exceptions -fno-rtti
ASFLAGS = $(CFLAGS)

LIBS = -lpsppower -lz -lm -lpspdebug -lpspgu -lpspaudiolib -lpspaudio -lpspaudiocodec -lpsprtc -lpspmp3
# -lpspaudio_driver

EXTRA_TARGETS = EBOOT.PBP
PSP_EBOOT_TITLE = 
PSP_EBOOT_ICON = 
PSP_EBOOT_PIC1 = 

PSPSDK=$(shell psp-config --pspsdk-path)
include $(PSPSDK)/lib/build.mak
hrydgard commented 8 months ago

thanks, this is a good start of an investigation! Already know that our mp3 stuff is wrong, it's not working well in some games that allow using mp3 as custom background music.

Nabile-Rahmani commented 3 months ago

Thanks for reporting this.

I looked into it way back in december (used to play on an old high-FPS build), before also giving up. Here were my notes:

SimpleAudio::Decode is ducked.

See the overview on API usage for avcodec{send,receive}{packet,frame}. Something's ducked up with how some codecs require draining the output before sending more stuff.

What's happening in particular is that after 1/2 frames, we receive a frame length that contains two frames, as reported by the logger. So audio breaks.

You can mess around with the order and it'll play choppily before hanging, so investigate.

FindNextMp3Sync() might be broken ? Think it decides the offset to the frame data ?

I may try to bang my head against this some more.

With the ffmpeg output draining taken care of, we can isolate this issue to PPSSPP's MP3 handler, correct ? Is FindNextMp3Sync() a good place to focus on ?

EDIT: I was about to look into it again and it looks like it's somehow been fixed in 1.17.1.

hrydgard commented 1 month ago

In the latest builds, we no longer use FFMPEG here for the mp3 format, instead we spawn an "MiniMp3Audio" decoder, which uses the minimp3 library directly, in order to have more control. That said, we still have some issues here, as can been seen in #14812 ..

I'm going to test your player soon.

hrydgard commented 1 month ago

Yeah, your code now plays music correctly, however there seems to be minor glitches between frames or something. Could be an issue with buffering in audio output, or something else..