Only one custom music track plays in NHL Legacy

[nik5830]

Quick summary

In NHL Legacy custom music plays only briefly at the start of a match, then
becomes permanently silent. Investigation of the log shows this is not a
decode failure — cellMusicDecode HLE implementation appears to decode the
entire MP3 file at maximum CPU speed instead of at playback rate, causing
the game to receive status=1 (decode finished) prematurely and issue
SetDecodeCommand2(STOP) before the audio has actually been heard.

Reproduction steps

1. Place a custom MP3 in dev_hdd0/music/<folder>/
2. Boot NHL Legacy, configure custom music in EA Trax Manager
3. Start a match

Observed behavior (from log)

Music Decode Thread decoder timestamps:

• At wall-clock 0:02:00.262 decoder starts on mix.mp3
• At wall-clock 0:02:05.654 (5.4 seconds later) decoder logs
  timestamp_us=14148034560 — i.e. ~3 hours 55 minutes of audio decoded
• Decoder then logs waiting until track is consumed...

Game-side reaction:

• At 0:03:14.148 game calls cellMusicDecodeGetDecodeStatus2 →
  returns status=1
• Immediately after, game calls cellMusicDecodeSetDecodeCommand2(0x0) (STOP)
• Decoder logs finished playlist
• 36 seconds later, EAAudioCore Dac thread begins calling
  cellMusicDecodeRead2 to consume buffered audio — every call fails with
  CELL_MUSIC_DECODE_ERROR_NO_LPCM_DATA (8000+ occurrences in the log)
• No further SetDecodeCommand2(START) is issued — music is silent for
  the rest of the session

Expected behavior

cellMusicDecode should produce decoded PCM data at approximately the
playback rate of the source, not at maximum CPU speed. status=1 should
arrive only when the actual audio content has been delivered to the game,
not when the source file has been fully read from disk and decoded into a
buffer. This matches the real PS3 behavior where decoding and playback
are tied to the audio hardware clock.

System configuration

• RPCS3 build: 0.0.40-19381-2613d7ee Alpha
• OS: Windows
• Game: NHL Legacy Edition [serial — подставь свой, BLUS31418 или BLES02220]
• Custom music: single MP3 file, ~4 hours, re-encoded via
  ffmpeg -map_metadata -1 -id3v2_version 3 -c:a libmp3lame -b:a 192k -ar 44100 -ac 2

Attachments

Full log: RPCS3.log.gz (attached)
Filtered music_lines.txt (attached) showing the complete cellMusicDecode
call sequence including the race between Music Decode Thread and
EAAudioCore Dac thread.

Related

This may be related to but is distinct from #12309 (which describes
decode-level LPCM failures). In the present issue, the decoder works
correctly — the failure mode is the racing between decoder output speed
and game-side playback consumption.

[nik5830]

Bumping with detailed diagnosis. Original report was missing the key
finding: this is a race condition in HLE cellMusicDecode, not a decode
failure. The decoder logs show the entire MP3 file is processed in ~5
seconds of wall-clock time, after which the game polls status, sees
"finished", and stops playback. Suspect cellMusic.cpp Music Decode Thread
needs throttling to playback rate. Happy to test any proposed fix.

[Megamouse]

While your effort is recommendable, you neither provided a log file nor an example track (keeping in mind copyright)

[nik5830]

While your effort is recommendable, you neither provided a log file nor an example track (keeping in mind copyright)

music_lines.txt

RPCS3.log.gz

[nik5830]

While your effort is recommendable, you neither provided a log file nor an example track (keeping in mind copyright)

mix.mp3

[nik5830]

While your effort is recommendable, you neither provided a log file nor an example track (keeping in mind copyright)

RPCS3_log.zip

[Darkhost1999]

Possibly fixed in a recent merged pr please retest