Closed JoergAtGithub closed 1 year ago
I noticed, that after switching the Skin or the Color scheme the cover art is always drawn correct for all decks.
Note, that the Library Coverart is always shown - this bug affects only the Deck/Spinny Coverart
Can you play the track if there's no cover?
Yes, everything works, just the Coverart image in the Deck/Spinny is randomly ~50% missing
This still occurs with any 2.4 build for me, while 2.3.5 work flawless. Occurs on two laptops with Win7 and Win11.
Do you see any related warnings when loading a track? Is the default cover shown? I mean the one set by the skin, not the global default. This is the Tango default
1.) The only messages about cover art are these, which I posted in the descriptions. But I'm not sure if these are related here.
2.) The default cover is shown if no CoverArt is displayed
3.) When I switch skins in the preferences, the CoverArt appears for all decks where a track is loaded => The bug only happens at loading tracks into a deck. No difference if I do this by double-click, drag and drop or controller mapping.
Any idea how to debug this?
Maybe an issue in CoverInfoGuesser().guessAndSetCoverInfoForTrack()
?
Or check what happens in CoverArtCache::requestTrackCover()
when you load a track?
CoverInfoGuesser().guessAndSetCoverInfoForTrack()
is not executed when I load a track into a deck.
If I set a breakpoint in Line 70 of https://github.com/mixxxdj/mixxx/blob/3de29630a80513127f8d3c0e5eb006922d240d08/src/library/coverartcache.cpp#L64-L74 it fails always. I guess this is some kind of race condition.
CoverArtCache::requestTrackCover is always executed, the breakpoint always triggers, for cases where the CoverArt is loaded and for the cases, where it does not. I've difficulties to debug this further. The CoverArtCache code is difficult to understand - and it's very hot code - very often executed by the library code. Breakpoints are only usable with additional conditions. But I wonder if the root cause might be in the Spinny widget code instead.
I think you could inspect the cover data in slotCoverFound
.
I'm a step further. The following function is executed three times, when a track is loaded into a deck. The first two times pixmap is alway NULL and it returns early. The third call differs in failure case, when the Coverart is not loaded, pixmap is NULL as well. https://github.com/mixxxdj/mixxx/blob/4a51c393eb8820a5728f4b2b53dce8ef203d2b8c/src/widget/wspinnybase.cpp#L377-L386
In case of not displayed CoverArt, WSpinnyBase::slotCoverFound
is called with an empty pixmap.
I'd like to reproduce this but on macOS I've never seen this happen. Are there any specific steps to make this more likely to occur?
This occurs on Windows most of the times (roughly 90% of the track loads the CoverArt in the spinnies is missing). I don't need to do anything special. The other way around I can say, what always work to display the CoverArt: If I switch the skin in the preferences while tracks are loaded into the decks, all decks will show the CoverArt after the skin change - until I load a new track to the deck, than the problem occurs again.
I don't think this will make a difference, but just in case, can you check with the old spinny implementation by returned a new WSpinny instead of a new WSpinnyGLSL in LegacySkinParser::parseSpinny ?
As running this in the debugger is tricky, you could add some more logging in the CoverArtCache and WSpinnyBase code to see where the difference between successful and null pixmaps occurs exactly.
Btw, while looking at the code, this std::move seems very strange to me.
271 emit coverFound(
272 res.pRequestor,
273 std::move(res.coverArt),
274 pixmap,
275 res.requestedCacheKey,
276 res.coverInfoUpdated);
Btw, while looking at the code, this std::move seems very strange to me.
Good catch, but since the signal parameters just take/pass lvalue refs, I'm pretty sure it doesn't do anything.
Btw, while looking at the code, this std::move seems very strange to me.
Good catch, but since the signal parameters just take/pass lvalue refs, I'm pretty sure it doesn't do anything.
Yes, I tried to change this already, but it doesn't fix this bug.
Could you add a lot of logging in all the functions involved and share the logs of a cover does and a cover that doesn't load?
I added a debug statement after each emit coverFound
. See the log below.
Only the last loaded track showed the CoverArt in the Spinny.txt
Maybe related test fails are in the Qt6 CI builds: https://github.com/mixxxdj/mixxx/actions/runs/6021023487/job/16343828636
Sorry for not getting back to you, @JoergAtGithub . I have been very busy. I will try to find some time to look into this this weekend.
In the meantime, maybe you already tried this, if not can you try if this also happens with the non-GLSL spinnies, by returned new WSpinny instead of WSpinnyGLSL in the legacyskinparser.cpp around line 1322 ?
This bug occurs with all waveform types. To clarify, this bug was introduced long time before merging #10989, but doesn't affect any 2.3 build.
Some takeaways:
SoundSourceProxy::importTrackMetadataAndCoverImageFromFile
fixes the issue. emit coverFound
. The request is executed but for some reasons there is NoImage
returned.WSpinnyBase
is affected, we see the issue also with DlgCoverArtFullSize
warning [Thread (pooled)] TagLib - Cannot read audio properties from inaccessible/unreadable/invalid file: ""
from https://github.com/mixxxdj/mixxx/blob/50675965e79caa7abdda07107f1d06a719ecbe51/src/track/taglib/trackmetadata_file.cpp#L128So it looks like the file becomes invalid somehow.
Can you uncomment this and check if the file name is still valid? https://github.com/mixxxdj/mixxx/blob/50675965e79caa7abdda07107f1d06a719ecbe51/src/sources/metadatasourcetaglib.cpp#L98
Maybe the vcpkg build environment for Windows is broken somehow?
Wow, that's wild (Qt6, main + ...):
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" with type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" with type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" with type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" with type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" with type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" with type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" with type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" with type 3
[New Thread 0x7fff1f1a86c0 (LWP 7456)]
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" with type 3
warning [AnalyzerThread 0 #1] SoundSourceFFmpeg - av_seek_frame() failed: Operation not permitted
warning [AnalyzerThread 0 #1] AudioSource - Failed to read sample frames: expected = [0 -> 1) , actual = [0 -> 0)
info [AnalyzerThread 0 #1] AudioSource - Shrinking readable frame index range: before = [0 -> 16816943) , after = [0 -> 0)
warning [AnalyzerThread 0 #1] AudioSource - Read test failed: expected = [0 -> 1) , actual = [0 -> 0)
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" with type 3
warning [AnalyzerThread 0 #1] SoundSourceProxy - Failed to read file "file:///home/uk/Music/1st/*****.mp3" with provider "FFmpeg"
All this happens while loading a single file into a deck. The cover art of the file is imported 9 times! The subsequent read failures reported by FFmpeg are really worrisome.
And the winner is: DlgCoverArtFullSize. Even though it should not be involved at all! With WSpinnyBase as a close follower. Which should also not be involved, because I don't have any spinnies with cover art enabled. The only expected request is the one from WCoverArt.
info [Main] DlgCoverArtFullSize: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] WCoverArt: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] DlgCoverArtFullSize: requestTrackCover "/home/uk/Music/1st/*****.mp3"
[New Thread 0x7fffd9a9d6c0 (LWP 11853)]
info [Main] WSpinnyBase: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
[New Thread 0x7fff1b86b6c0 (LWP 11854)]
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
info [Main] DlgCoverArtFullSize: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] WSpinnyBase: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] DlgCoverArtFullSize: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] WSpinnyBase: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] DlgCoverArtFullSize: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] WSpinnyBase: requestTrackCover "/home/uk/Music/1st/*****.mp3"
Looks like there are some serious issues in the application's control flow.
On Windows, the file access of Mixxx in general, is rather slow. I guess that this increases the likelyhood that the race condition results in a not loaded CoverArt.
The results from a Qt5 build don't look any better:
info [Main] MetadataSourceTagLib - Importing track metadata from file "/home/uk/Music/1st/*****.mp3" of type 3
info [Main] WCoverArt: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
warning [CachingReaderWorker 1] SoundSourceFFmpeg - av_seek_frame() failed: Operation not permitted
warning [CachingReaderWorker 1] AudioSource - Failed to read sample frames: expected = [0 -> 1) , actual = [0 -> 0)
info [CachingReaderWorker 1] AudioSource - Shrinking readable frame index range: before = [0 -> 16816943) , after = [0 -> 0)
warning [CachingReaderWorker 1] AudioSource - Read test failed: expected = [0 -> 1) , actual = [0 -> 0)
warning [CachingReaderWorker 1] SoundSourceProxy - Failed to read file "file:///home/uk/Music/1st/*****.mp3" with provider "FFmpeg"
info [CachingReaderWorker 1] SoundSourceMp3 - Recoverable MP3 header decoding error: lost synchronization
info [CachingReaderWorker 1] SoundSourceMp3 - MP3 frame header | layer: 3 mode: 2 #channels: 2 #samples: 36 bitrate: 320000 samplerate: 44100 flags: "0x00c8"
info [Main] DlgCoverArtFullSize: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] WCoverArt: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] DlgCoverArtFullSize: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] WSpinnyBase: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] DlgCoverArtFullSize: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] WSpinnyBase: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
info [Main] DlgCoverArtFullSize: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
info [Main] WSpinnyBase: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] DlgCoverArtFullSize: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Main] WSpinnyBase: requestTrackCover "/home/uk/Music/1st/*****.mp3"
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
info [Thread (pooled)] MetadataSourceTagLib - Importing cover art from file "/home/uk/Music/1st/*****.mp3" of type 3
warning [AnalyzerThread 0 #1] SoundSourceFFmpeg - av_seek_frame() failed: Operation not permitted
warning [AnalyzerThread 0 #1] AudioSource - Failed to read sample frames: expected = [0 -> 1) , actual = [0 -> 0)
info [AnalyzerThread 0 #1] AudioSource - Shrinking readable frame index range: before = [0 -> 16816943) , after = [0 -> 0)
warning [AnalyzerThread 0 #1] AudioSource - Read test failed: expected = [0 -> 1) , actual = [0 -> 0)
warning [AnalyzerThread 0 #1] SoundSourceProxy - Failed to read file "file:///home/uk/Music/1st/*****.mp3" with provider "FFmpeg"
Things are seriously broken. Unfortunately no crashes yet, which could have helped to identify the root cause timely. Now someone has to start bisecting the repo.
@uklotzde If this is the log from loading a track to a deck, and you use Deere for example, I'm pretty sure all those requests are to be expected.
because I don't have any spinnies with cover art enabled
If you use Deere for example the spinnies are instantiated even if you disabled the in the skin settings. Same for DlgCoverArtFullsize which is created for both spinnies and WCoverArt and connected to CoverArtCache signals. All those widgets request a cover when a track is loaded to a player.
The failures of FFmpeg are unrelated and caused by a recent regression: #11923
Adding some conditionals in DlgCoverArtFullSize and WSpinnyBase fixes the excessive loading and everything still seems to work as expected. But I can't proove why, don't expect a PR.
Thi fix can be found here: https://github.com/mixxxdj/mixxx/pull/12103
Bug Description
If I load a track into a deck, the CoveArt is sometimes displayed, and sometimes not. This doesn't depend on the track, it can be reproduced for any track after some retries. This doesn't happen with 2.3, only with Main.
In the --developer output I see in cases without loaded coverart:
Version
2.4
OS
Windows7 & Windows11