track plays but without sound

[Philip Gottschling]

I currently face the problem that probably every second time (in the same deck) I load a track and start playing it there is no sound output on that deck.
The Waveform shows that the track is played but the mixer does not indicate any signal. PFL output has no sound either.

If I load the same track to the same deck again sound works.

In the log attached the first track plays with sound, the second one does not, and then again loaded it plays with sound.
Unfortunately the log does not seem to ouput anything related to that. Or do I miss something?

I am running the current master [584c6c8b116cb623b592fa53961cb0808477068c].

[Uwe Klotz (uklotzde-deactivatedaccount)]

Does this also happen if you start with a fresh configuration?

[Be (be.ing)]

I noticed this a few times recently. Loading a different track worked, then loading the affected track again reproduced the bug. However I have not been able to reproduce this since running "scons -c" and doing a full rebuild.

[jus (jus)]

Have seen this too with latest master, and existing configuration.
Macos 10.14.6 (18G95)

[Uwe Klotz (uklotzde-deactivatedaccount)]

I didn't experience this issue a single time, although I'm constantly using master.

It doesn't seem to depend on the compiler, platform, sound interface, or decoder since it has been reported for both macOS and Linux.

[Uwe Klotz (uklotzde-deactivatedaccount)]

There were some changes in CachingReader, though I'm using the same version constantly without any issues.

Did those issues occur with a debug or a release build?

[jus (jus)]

In my case:
Debug [Main]: "Mixxx" "2.3.0-alpha-pre" "(git master r6957; built on: Sep 29 2019 @ 12:03:53; flags: asan=0 battery=1 buildtime=1 bulk=0 color=0 coreaudio=1 faad=0 ffmpeg=0 hid=1 hss1394=0 lilv=1 localecompare=0 macappstore=0 mad=0 mediafoundation=0 modplug=1 optimize=portable opus=1 perftools=0 perftools_profiler=0 profiling=0 qt_sqlite_plugin=0 qtkeychain=0 shoutcast=1 test=0 tsan=0 ubsan=0 verbose=0 vinylcontrol=1 wv=0)" is starting...
Debug [Main]: Compile time library versions:
Debug [Main]: Qt: 5.13.0
Debug [Main]: libshout: 2.4.3
Debug [Main]: PortAudio: 1246720 PortAudio V19.6.0-devel, revision 396fe4b6699ae929d3a685b3ef8a7e97396139a4
Debug [Main]: RubberBand: 1.8.2
Debug [Main]: SoundTouch: 2.1.1
Debug [Main]: TagLib: 1.11.1
Debug [Main]: ChromaPrint: 1.4.3
Debug [Main]: Vorbis: Xiph.Org libVorbis 1.3.6
Debug [Main]: libsndfile: libsndfile-1.0.28
Debug [Main]: FLAC: 1.3.2
Debug [Main]: libmp3lame: 3.100

[Be (be.ing)]

I think we should fix this before releasing 2.3 beta.

[Uwe Klotz (uklotzde-deactivatedaccount)]

I'm not able to reproduce this bug, neither in debug or release builds nor with different analysis, waveform, effect, and quantize settings or with different decoders. How hard do I need to try? I could also try to switch to Clang instead of GCC to reduce the degrees of freedom.

The first commit that includes the CachingReader fixes is bdc87af0852da845c9f34c3c85c1a9fcb7dc994d (Merge remote-tracking branch 'upstream/2.2').

The last commit on master that does NOT contain the CachingReader fixes is e9514640285b27fe31e073b34d1d052dd7a3792e (Merge pull request #2269 from goddisignz/quantized_loop_out_2.2). Are you able to reproduce the bug with this version?

[Uwe Klotz (uklotzde-deactivatedaccount)]

I noticed that there is another fix pending (since about a month now) that I discovered independently:

https://github.com/mixxxdj/mixxx/pull/2252

I will check how this might affect the "readableFrameIndexRange" that needs to be pushed upstream by the workers to detect and exclude corrupt ranges in the audio stream.

[Uwe Klotz (uklotzde-deactivatedaccount)]

But it should work even without this fix that is not part of 2.2!

[Be (be.ing)]

Philip and jus, what format have the affected files been? I only have FLAC files, so I do not know if the bug might depend on the file format. This might somehow be related to the recent changes of the FFMPEG SoundSource, though I don't know how.

[jus (jus)]

the mediainfo for the file shown in screencast #8

Again, this is not always when playing this track, but i found no pattern yet.

[Uwe Klotz (uklotzde-deactivatedaccount)]

I have an idea what could go wrong. Communication between CachingReader and its worker while unloading/loading tracks. Pending read requests that are discarded might reset the range.

[Uwe Klotz (uklotzde-deactivatedaccount)]

https://github.com/mixxxdj/mixxx/pull/2305

Please cherry-pick and test this commit!! The CachingReader is still a beast that is hard to tame :((

[Philip Gottschling (goddisignz)]

I just tested with an empty .mixxx folder (why didn't I think about that) and the music always plays correctly.

The problem starts when I add my mixxxdb.sqlite to the .mixxx folder.
I will try the cherry-pick and then post again.

[Philip Gottschling (goddisignz)]

Thanks Uwe, the cherry-pick did the trick!

It is interesting to see that songs that I have not yet played with the cherry pick take a short time to analyze when loaded. Songs that were already played load without any analysis. Also after closing and reopening mixxx.

Can I tell if my database format is from a (to) old version?
Is anyone interested in my "old" database for testing purposes?

[Uwe Klotz (uklotzde-deactivatedaccount)]

I've added another commit that improves and simplifies the state machine of CachingReader. Please test again. If no new issues occur this bug should be fixed.

From the PR: The main cause for the bug was the invalid ordering of updates by the worker thread, i.e. first inserting the track loaded message, followed by invalid, discarded chunks from pending read requests for the previous track.

[Uwe Klotz (uklotzde-deactivatedaccount)]

In 2.2.2 the worker already sends updates in the wrong order, but the consequences are more subtle. Only if the old track is shorter it is possible that the new track stops earlier than expected. The length is not zeroed but only shortened! I remember that we had a bug report about tracks that stopped too early. Those are hopefully fixed now.

Due to the more restrictive length checking and handling introduced recently this critical bug could finally be discovered!!

[Uwe Klotz (uklotzde-deactivatedaccount)]

The bug was present since at least 2.2.0, maybe even earlier.

[Philip Gottschling (goddisignz)]

I tested the master with Uwes merged PR and can not produce the bug any more.
So from my side this seems to be fixed. Thanks for all the help!

[Swiftb0y (swiftb0y)]

Mixxx now uses GitHub for bug tracking. This bug has been migrated to:
https://github.com/mixxxdj/mixxx/issues/9755