strawberrymusicplayer / strawberry

:strawberry: Strawberry Music Player
https://www.strawberrymusicplayer.org/
GNU General Public License v3.0
2.76k stars 194 forks source link

Rare crash in `gst/playback/gstplaybin3.c` #1617

Open qarmin opened 1 day ago

qarmin commented 1 day ago

Describe the bug When playing music, randomly(and rarely, maybe 1 time per month) strawberry crashes

org.strawberrymusicplayer.strawberry.desktop[65963]: ERROR:../gst/playback/gstplaybin3.c:2617:reconfigure_output: assertion failed: (combine->sinkpad == NULL)
org.strawberrymusicplayer.strawberry.desktop[65963]: Bail out! ERROR:../gst/playback/gstplaybin3.c:2617:reconfigure_output: assertion failed: (combine->sinkpad == NULL)

just before crash I see in logs "Internal data stream error" and other errors, that can be related to this bug

21:22:48.600 DEBUG MainWindow:1474                  Song changed to "Pale Waves" "Thinking About You" "Perfume"
21:22:48.600 INFO  MoodbarLoader:144                Loading cached moodbar data for "/home/rafal/Desktop/AAA/Pale Waves/Thinking About You/Perfume.mp3"
21:22:48.601 DEBUG Player:776                       Playing song "Perfume" QUrl("file:///home/rafal/Desktop/AAA/Pale Waves/Thinking About You/Perfume.mp3") position 0
21:22:48.602 DEBUG GstEnginePipeline:789            Setting buffer duration: 4000000000 low watermark: 0.33 high watermark: 0.99
21:22:48.602 DEBUG GstEnginePipeline:415            Finishing pipeline 2
21:22:48.602 DEBUG GstEnginePipeline:1797           Setting pipeline 2 state to "Null"
21:22:48.603 DEBUG GstEnginePipeline:1797           Setting pipeline 3 state to "Paused"
21:22:48.603 DEBUG GstEnginePipeline:1659           Pipeline state changed from "Null" to "Ready"
21:22:48.610 ERROR GstEnginePipeline:1545           ErrorMessageReceived ID: 3 Domain: 3831 Code: 1 Error: "Internal data stream error."
21:22:48.610 ERROR GstEnginePipeline:1546           ErrorMessageReceived ID: 3 Domain: 3831 Code: 1 Debug: "../libs/gst/base/gstbaseparse.c(3702): gst_base_parse_loop (): /GstPlayBin3:pipeline-3-pipeline/GstURIDecodeBin3:uridecodebin3/GstURISourceBin:urisourcebin4/GstParseBin:parsebin4/GstMpegAudioParse:mpegaudioparse9:\nstreaming stopped, reason not-linked (-1)"
21:22:48.610 DEBUG GstEnginePipeline:1360           Stream from URL "file:///home/rafal/Desktop/AAA/Pale%20Waves/Thinking%20About%20You/Perfume.mp3" about to finish.
21:22:48.610 DEBUG TagReaderTagLib:1311             Loading cover from "/home/rafal/Desktop/AAA/Pale Waves/Thinking About You/Perfume.mp3"
21:22:48.615 DEBUG GstEnginePipeline:994            "pipeline-3-autoaudiosink-actual-sink-pulse" has volume, enabling volume synchronization.
21:22:48.615 DEBUG GstEnginePipeline:934            Connecting volume notify on 0x773ac000c160
21:22:48.629 INFO  MoodbarLoader:144                Loading cached moodbar data for "/home/rafal/Desktop/AAA/Kylie Minogue/Tension II/Hello.mp3"
21:22:48.631 DEBUG GstEnginePipeline:1719           Buffering started
21:22:48.632 DEBUG GstEnginePipeline:1730           Buffering finished
21:22:48.635 DEBUG GstEnginePipeline:1818           Pipeline 3 state successfully set to "Paused"
21:22:48.636 DEBUG GstEnginePipeline:1818           Pipeline 2 state successfully set to "Null"
21:22:48.636 DEBUG GstEngine:964                    Pipeline 2 finished
21:22:48.636 DEBUG GstEnginePipeline:210            Pipeline 2 deleted
21:22:48.637 DEBUG GstEngine:974                    1 pipelines are active
21:22:48.637 ERROR GstEngine:611                    GStreamer error: 3831 1 "Internal data stream error."
21:22:48.637 DEBUG Lazy<T>:67                       ErrorDialog(0x58b75912bd10, name="ErrorDialog") created
21:22:48.640 DEBUG GstEnginePipeline:415            Finishing pipeline 3
21:22:48.640 DEBUG GstEnginePipeline:1797           Setting pipeline 3 state to "Null"
Window manager warning: Invalid WM_TRANSIENT_FOR window 0x4000008 specified for 0x400003c.
21:22:48.643 DEBUG TemporaryFile:43                 Temporary file "/tmp/strawberry-cover-xl51al.jpg" available
21:22:48.644 DEBUG TemporaryFile:51                 Deleting temporary file "/tmp/strawberry-cover-3n7kbn.jpg"
21:22:48.646 DEBUG TemporaryFile:43                 Temporary file "/tmp/strawberry-cover-93zb8l.jpg" available
21:22:48.646 DEBUG TemporaryFile:51                 Deleting temporary file "/tmp/strawberry-cover-uxtx9i.jpg"
21:22:48.646 WARN  unknown                          QDBusObjectPath: invalid path "/org/strawberrymusicplayer/strawberry/Track/-1"
21:22:48.647 DEBUG GstEnginePipeline:1797           Setting pipeline 3 state to "Playing"
**
ERROR:../gst/playback/gstplaybin3.c:2617:reconfigure_output: assertion failed: (combine->sinkpad == NULL)
Bail out! ERROR:../gst/playback/gstplaybin3.c:2617:reconfigure_output: assertion failed: (combine->sinkpad == NULL)
10:16:38.608 DEBUG MainWindow:1474                  Song changed to "Andi" "Everyone's the Same" "Everyone's the Same"
10:16:38.650 INFO  MoodbarLoader:144                Loading cached moodbar data for "/home/rafal/Desktop/AAA/Andi/Everyone's the Same/Everyone's the Same.mp3"
10:16:38.650 DEBUG Player:776                       Playing song "Everyone's the Same" QUrl("file:///home/rafal/Desktop/AAA/Andi/Everyone's the Same/Everyone's the Same.mp3") position 0
10:16:38.651 DEBUG GstEnginePipeline:789            Setting buffer duration: 4000000000 low watermark: 0.33 high watermark: 0.99
10:16:38.651 DEBUG TagReaderTagLib:1311             Loading cover from "/home/rafal/Desktop/AAA/Andi/Everyone's the Same/Everyone's the Same.mp3"
10:16:38.651 DEBUG GstEnginePipeline:415            Finishing pipeline 2
10:16:38.651 DEBUG GstEnginePipeline:1797           Setting pipeline 2 state to "Null"
10:16:38.652 DEBUG GstEnginePipeline:1797           Setting pipeline 3 state to "Paused"
10:16:38.652 DEBUG GstEnginePipeline:1659           Pipeline state changed from "Null" to "Ready"
10:16:38.658 ERROR GstEnginePipeline:1545           ErrorMessageReceived ID: 3 Domain: 3834 Code: 1 Error: "Internal data stream error."
10:16:38.658 ERROR GstEnginePipeline:1546           ErrorMessageReceived ID: 3 Domain: 3834 Code: 1 Debug: "../libs/gst/base/gstbaseparse.c(3702): gst_base_parse_loop (): /GstPlayBin3:pipeline-3-pipeline/GstURIDecodeBin3:uridecodebin3/GstURISourceBin:urisourcebin5/GstParseBin:parsebin5/GstMpegAudioParse:mpegaudioparse11:\nstreaming stopped, reason not-linked (-1)"
10:16:38.658 DEBUG GstEnginePipeline:1360           Stream from URL "file:///home/rafal/Desktop/AAA/Andi/Everyone's%20the%20Same/Everyone's%20the%20Same.mp3" about to finish.
10:16:38.663 DEBUG GstEnginePipeline:994            "pipeline-3-autoaudiosink-actual-sink-pulse" has volume, enabling volume synchronization.
10:16:38.663 DEBUG GstEnginePipeline:934            Connecting volume notify on 0x7b296809ffd0
10:16:38.680 DEBUG GstEnginePipeline:1719           Buffering started
10:16:38.680 DEBUG GstEnginePipeline:1730           Buffering finished
10:16:38.680 INFO  MoodbarLoader:144                Loading cached moodbar data for "/home/rafal/Desktop/AAA/Liza/The Alternate Ending (Deluxe)/Alternate Ending.mp3"
10:16:38.686 DEBUG GstEnginePipeline:1818           Pipeline 3 state successfully set to "Paused"
10:16:38.686 DEBUG TemporaryFile:43                 Temporary file "/tmp/strawberry-cover-9opx59.jpg" available
10:16:38.686 DEBUG TemporaryFile:51                 Deleting temporary file "/tmp/strawberry-cover-l4smoh.jpg"
10:16:38.688 DEBUG TemporaryFile:43                 Temporary file "/tmp/strawberry-cover-cx6iv3.jpg" available
10:16:38.688 DEBUG TemporaryFile:51                 Deleting temporary file "/tmp/strawberry-cover-7rgjy9.jpg"
10:16:38.690 DEBUG GstEnginePipeline:1818           Pipeline 2 state successfully set to "Null"
10:16:38.690 DEBUG GstEngine:964                    Pipeline 2 finished
10:16:38.690 DEBUG GstEnginePipeline:210            Pipeline 2 deleted
10:16:38.690 DEBUG GstEngine:974                    1 pipelines are active
10:16:38.690 ERROR GstEngine:611                    GStreamer error: 3834 1 "Internal data stream error."
10:16:38.697 DEBUG Lazy<T>:67                       ErrorDialog(0x56ef106723c0, name="ErrorDialog") created
10:16:38.699 DEBUG GstEnginePipeline:415            Finishing pipeline 3
10:16:38.699 DEBUG GstEnginePipeline:1797           Setting pipeline 3 state to "Null"
10:16:38.702 DEBUG GstEnginePipeline:1797           Setting pipeline 3 state to "Playing"
**
ERROR:../gst/playback/gstplaybin3.c:2617:reconfigure_output: assertion failed: (combine->sinkpad == NULL)
Bail out! ERROR:../gst/playback/gstplaybin3.c:2617:reconfigure_output: assertion failed: (combine->sinkpad == NULL)

Maybe it would be useful if the application was also available in compiled form with address sanitizer to catch bugs faster?

To Reproduce Not really reproducible - happens too rarely

System Information:

jonaski commented 1 day ago

Looks like a GStreamer bug

jonaski commented 1 day ago

Looks to be fixed in GStreamer 1.24.3 https://gitlab.freedesktop.org/gstreamer/gstreamer/-/issues/3389

qarmin commented 1 day ago

Looks that crash is triggered by invalid audio file, but I have in my collection, only valid files(this crashes randomly once, not each time with same configurations)

I think, that there might be also a bug in strawberry, that activated this crash. QDBusObjectPath: invalid path "/org/strawberrymusicplayer/strawberry/Track/-1" this line I see in strawberry logs(10 times since 10 days)