adding large amount of files while playing leads to freeze

[dogo77]

Bug Description

Mixxx started as usual, Laptop, AMD 5 5500U, 16GB RAM, Roland 505 as Midi Controller

· Co-DJ showed up with USB Stick, ~210 Songs, 5GB · copied to local filesystem (ssd) · we triggered NO library scan · he selected the songs from filesystem tree within mixxx

suddenly (after ~30 Minutes into his play) mixxx became unresponsive in parts Music was playing, but loading/unloading of songs did not work, no response to controller input. library was responsive, an i think we added further load to the system by panicly trying to add lifesaver song to another deck. Songs got added (!), but did not play.

End of story: the playing song ended, no following song was playable. Had to terminate mixxx and restart. Crowd was cool with "some technical problems", but still i want to understand what happened here ;)

mixxx.log

any idea?

Version

2.4.1

OS

Archlinux

[Swiftb0y]

End of story: the playing song ended, no following song was playable.

Do you remember which song that was so we can find the corresponding spot in the log better? Other than that, I have no idea. A couple things I've noticed:

Warning [Controller] Timer request for 1 ms is too short. Setting to the minimum of 20ms.`.

What controller would that be?

Debug [Main] Ignoring drag enter event, loading not allowed Warning [Main] MixxxMainWindow(0x7ffe43d65fe0) : No drag target set.

Maybe DnD is at fault?

Info [AnalyzerThread 3 #4] SoundSourceMp3 - Recoverable MP3 header decoding error: lost synchronization 627

almost all tracks that got loaded have a decoding error. Not sure how common that is in reality.

[dogo77]

Do you remember which song that was so we can find the corresponding spot in the log better?

Gigi D’Agostino - Bla Bla Bla was playing in deck 1 Vois sur ton chemin (Techno Mix) was loaded into deck 2 transition was planed from deck 1 to deck 2

What controller would that be?

Roland DJ-505 with mapping from mixxx (no modifications)

Debug [Main] Ignoring drag enter event, loading not allowed Warning [Main] MixxxMainWindow(0x7ffe43d65fe0) : No drag target set.

Maybe DnD is at fault?

I do load songs by double clicking in library or pushing »load button« on controller He does drag'n'drop

Info [AnalyzerThread 3 #4] SoundSourceMp3 - Recoverable MP3 header decoding error: lost synchronization 627 almost all tracks that got loaded have a decoding error. Not sure how common that is in reality.

The files came from his laptop, running mixxx 2.4.1 on linux. they were exported via playlist --> export track files we will check whether the files are already corrupt on his laptop.

[acolombier]

Music was playing, but loading/unloading of songs did not work, no response to controller input.

Was the UI frozen? Could you still move faders and knobs on the UI? Where the waveform still active? Or was it all stuck?

He does drag'n'drop

I can see the last track that was loaded by DnD is O-Zone - Dragostea Din Tei (Numa Numa) (Fahjah Remix).mp3, do you confirm? What happened then? Could you see the the waveform/metadata loading?

almost all tracks that got loaded have a decoding error. Not sure how common that is in reality.

we will check whether the files are already corrupt on his laptop.

Most of my files also show similar messages, but AFAIK, this mostly comes to IDv3 garbage or unsupported frames generated by other software, but they have no impact or playback degradation in my case.

Songs got added (!), but did not play.

What happens when try to play the track? Could you see the playback progressing but no sound? Was the playback stuck?

---

Some initial thought after trying to decipher this long log file:

• From my understanding of the engine, no playback (silence) or stuck playback will usually be related to an issue in either the [Main] thread or one of the [CachingReaderWorker X]. There is a large amount of message that seem to indicate the inability of the cache worker to read frames:

  Info [CachingReaderWorker 2] SoundSourceMp3 - Recoverable MP3 header decoding error: forbidden bitrate value 3462065
  Info [CachingReaderWorker 2] SoundSourceMp3 - MP3 frame header | layer: 1 mode: 2 #channels: 2 #samples: 12 bitrate: 128000 samplerate: 44100 flags: "0x0000"
  Info [CachingReaderWorker 2] SoundSourceMp3 - Recoverable MP3 header decoding error: forbidden bitrate value 3462066
  Info [CachingReaderWorker 2] SoundSourceMp3 - MP3 frame header | layer: 1 mode: 2 #channels: 2 #samples: 12 bitrate: 128000 samplerate: 44100 flags: "0x0000"
  Info [CachingReaderWorker 2] SoundSourceMp3 - Recoverable MP3 header decoding error: forbidden bitrate value 3462103
  Info [CachingReaderWorker 2] SoundSourceMp3 - MP3 frame header | layer: 1 mode: 2 #channels: 2 #samples: 12 bitrate: 128000 samplerate: 44100 flags: "0x0000"

  This could have lead to a "silence deck" although the deck appears to be playing was that the case?

• I can see a few instance of Ignoring drag enter event, loading not allowed message, happening after the load of the two tracks you've mentioned. This message indicated that that a track is currently playing and the so the deck will refuse to load a track
• Gut feeling is either an issue with the state management of the deck or CachingReaderWorker starvation/deadlock

Just to confirm the information you provided:

• You are using 2-deck or a 4-deck setup?
• Gigi D’Agostino - Bla Bla Bla was playing in deck 1, Vois sur ton chemin was loaded into deck 2, what happened next?
  • Was deck 2 showed as playing but silence? (That could correlate with my findings with the silence of CachingReaderWorker 2)
  • Where did you try to load the next track (O-Zone - Dragostea Din Tei?)? Deck 2?
  • If yes:
  • did you stop the playback?
  • did you try to eject the track from the deck?

[dogo77]

First of all: thanks for looking into it, sorry for the big log, and sorry for maybe not remembering all details, it happened 00:45 a.m., we were 6h into the gig and had a mildly accelerated heart rate at this moment. we realized maybe 45 seconds before the transition that something is wrong.

Music was playing, but loading/unloading of songs did not work, no response to controller input.

Was the UI frozen? Could you still move faders and knobs on the UI? Where the waveform still active? Or was it all stuck?

The UI was responsive. If i remember correctly I could move hardware faders and had a visual response from the UI

He does drag'n'drop

I can see the last track that was loaded by DnD is O-Zone - Dragostea Din Tei (Numa Numa) (Fahjah Remix).mp3, do you confirm? What happened then? Could you see the the waveform/metadata loading?

That was the "fallback track" we tried to load as we thought it is a rotten file problem or something like that. The problem started when Gigi D’Agostino - Bla Bla Bla was playing in deck 1 Vois sur ton chemin (Techno Mix) was loaded into deck 2

we could see the loaded track with the waveform visible in UI. just: hitting PLAY did nothing hitting CUE did nothing both on the controller AND when clicking the buttons in UI.

What happens when try to play the track? Could you see the playback progressing but no sound? Was the playback stuck?

Just nothing happened. No playback progressing, no sound (we raised volume on deck 2 and did a quick crossfade)

Some initial thought after trying to decipher this long log file:

* From my understanding of the engine, no playback (silence) or stuck playback will usually be related to an issue in      
  This could have lead to a "silence deck" although the deck appears to be playing was that the case?

If i understand your question correctly: the deck (2) seemed ready to play the song but refused to start playing or cueing

* I can see a few instance of `Ignoring drag enter event, loading not allowed` message, happening after the load of the two tracks you've mentioned. This message indicated that that a track is currently playing and the so the deck will refuse to load a track

If i remember correctly, we saw no visual indication that the deck (2 ) was actually playing anything, we did not hear anything, neither in PFL nor when opening the deck to master. (can't believe we did that XD )

Just to confirm the information you provided:

* You are using 2-deck or a 4-deck setup?
* `Gigi D’Agostino - Bla Bla Bla` was playing in deck 1, `Vois sur ton chemin` was loaded into deck 2, what happened next?

Some additional Info here: Usually i'm allways in 2 deck mode. As Panic increased we activated 4 deck mode and tried to load songs into deck 3 or 4 – not shure anymore – and tried to play from there, but that did not work either. Same behaviour (here i'm shure): track loaded, waveform visible, but the song did not start to play

  * Was deck 2 showed as playing but silence? (That could correlate with my findings with the silence of `CachingReaderWorker 2`)

Not shure here whether the UI showed the deck as playing or not. The PLAY button in the UI might have been orange, but i'm just not shure.

  * Where did you try to load the next track (`O-Zone - Dragostea Din Tei`?)? Deck 2?

Deck 2 and Deck 3, if i remember correctly. As said, it is really hard to reconstruct all the things we tried and did in this minute :\

  * If yes:

    * did you stop the playback?
    * did you try to eject the track from the deck?

i remember stopping/starting/stopping the playback in deck 2, unloading the track via the unload button in UI, loading track again, realizing that the song still does not play, trying another song, does not work, activating 4 deck mode, loading song to deck 3, not working, loading another song to deck 3, not working, 10 seconds left, okay, we let the playing song find it's end, close the program and restart.

with the fresh instance everything worked as usual as if nothing ever happened.

[acolombier]

Right, thanks for that night recall. From what you are saying, it feels like the CachingReaderWorker starvation/deadlock is my best theory so far, especially as you tried with "fresh" decks, which wouldn't have any previous corrupted state. With the library sync going on (on its own - suspecting the BrowseFeature to have triggered it) in the background + all the MP3 encoder error, that could have lead to block each workers one by one.

I'm afraid this is going to be one of those issue impossible to fix, till we stumble across something weird/largely refactor some part/get a way to reproduce sadly.

[dogo77]

:) I don't know if this experience is even right in the "bug" section. I just wanted to share what happened and tried to explain what led to that situation. Maybe that will help in the future. My learnings from that night: Don't try to add 5GB of new Songs in a live condition, have them loaded before, have them analyzed before. Things can happen :)