Bug 347979

Summary:	Amarok podcast stops randomly during playback
Product:	[Frameworks and Libraries] phonon-backend-vlc	Reporter:	phillip9001
Component:	general	Assignee:	Harald Sitter <sitter>
Status:	RESOLVED UPSTREAM
Severity:	major	CC:	bart.cerneels, bcooksley, fabo, jb, myriam
Priority:	NOR
Version First Reported In:	0.8.0
Target Milestone:	---
Platform:	Mint (Ubuntu based)
OS:	Linux
Latest Commit:		Version Fixed/Implemented In:
Sentry Crash Report:

Description phillip9001 2015-05-20 01:48:23 UTC

It started happening after I just added new podcasts to Amarok 2.8; it doesn't occur with songs on the local drives but it always stops randomly when playing podcasts.

Reproducible: Always

Steps to Reproduce:
1. Open amarok through Konsole and I typed: amarok -d --nofork ; to render any messages
2. Play podcast either in playlist or drive selection sources
3. Wait between quarter to a half an hour and it will stop.

Actual Results:  
When following the above procedure is performed, the podcast will stop randomly as mentioned before.

Expected Results:  
The software should keep playing without stopping randomly.

The program begins to initiate stop of the playback around the sixth line. The "QTimeLine::setPaused: Not running" occurs when I switch desktops through the KDE default renderer. I have tested to see if changing or minimizing amarok actually causes the podcast to stop, and it doesn't.
------------------------------------------

amarok: [EngineController] slotStateChanged from 3 to 2 
amarok: MPRIS2: Queueing up a PropertiesChanged signal 
QTimeLine::setPaused: Not running
QTimeLine::setPaused: Not running
QTimeLine::setPaused: Not running
amarok: BEGIN: void EngineController::slotAboutToFinish() 
amarok:   BEGIN: void Playlist::Actions::requestNextTrack() 
amarok:   END__: void Playlist::Actions::requestNextTrack() [Took: 0s] 
amarok: END__: void EngineController::slotAboutToFinish() [Took: 0s] 
amarok: BEGIN: void EngineController::slotFinished() 
amarok:   [EngineController] Track finished completely, updating statistics 
amarok:   [EngineController] slotTrackFinishedPlaying( "" - "Freedomain Radio with Stefan Molyneux" - "May 9th, 2015" , 1 ) 
amarok:   BEGIN: void TimecodeObserver::stopped(qint64, qint64) 
amarok:   END__: void TimecodeObserver::stopped(qint64, qint64) [Took: 0s] 
amarok:   BEGIN: void Playlist::Actions::slotPlayingStopped(qint64, qint64) 
amarok:     [Playlist::Actions] nothing more to play... 
amarok:     MPRIS2: Queueing up a PropertiesChanged signal 
amarok:     BEGIN: void Playlist::PrettyListView::slotPlaylistActiveTrackChanged() 
amarok:       BEGIN: void Playlist::PrettyListView::scrollToActiveTrack() 
amarok:       END__: void Playlist::PrettyListView::scrollToActiveTrack() [Took: 0s] 
amarok:     END__: void Playlist::PrettyListView::slotPlaylistActiveTrackChanged() [Took: 0s] 
amarok:     BEGIN: virtual void Playlist::Model::setAllUnplayed() 
amarok:     END__: virtual void Playlist::Model::setAllUnplayed() [Took: 0s] 
amarok:   END__: void Playlist::Actions::slotPlayingStopped(qint64, qint64) [Took: 0s] 
amarok:   [TabsApplet] updating interface from state  4  to  1 
amarok:   BEGIN: void OSDWidget::show(const QString&, const QImage&) 
amarok:   END__: void OSDWidget::show(const QString&, const QImage&) [Took: 0.007s] 
amarok:   BEGIN: void TabsEngine::update() 
amarok:     [TabsEngine] no track 
amarok:   END__: void TabsEngine::update() [Took: 0s] 
amarok: END__: void EngineController::slotFinished() [Took: 0.024s] 
amarok: [EngineController] slotStateChanged from 2 to 1 
amarok: [LyricsEngine] no current track 
amarok: MPRIS2: Queueing up a PropertiesChanged signal 
amarok: BEGIN: void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) 
amarok:   [EngineController] Empty MediaSource (engine stop) 
amarok: END__: void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) [Took: 0s] 
amarok: BEGIN: void TabsApplet::dataUpdated(const QString&, const Data&) 
amarok: END__: void TabsApplet::dataUpdated(const QString&, const Data&) [Took: 0s] 
Calling appendChild() on a null node does nothing.

-------------------------------------------------------------------
I would like to listen to my podcasts without having it randomly stop, and having to backtrack where I left off.

Comment 1 Myriam Schweingruber 2015-05-20 09:00:43 UTC

Can't reproduce this here, using Amarok from git master on Kubuntu, phonon backend gstreamer 4.7.80 and gstreamer 1.x plugins.

Which exact phonon backend do you use?
What is the file type of these podcasts?
If you listen to live podcasts: is your network stable?
If you listen to downloaded episodes: is the location accessible permanently?

Comment 2 phillip9001 2015-05-20 20:59:14 UTC

(In reply to Myriam Schweingruber from comment #1)
> Can't reproduce this here, using Amarok from git master on Kubuntu, phonon
> backend gstreamer 4.7.80 and gstreamer 1.x plugins.
> 
> Which exact phonon backend do you use?
> What is the file type of these podcasts?
> If you listen to live podcasts: is your network stable?
> If you listen to downloaded episodes: is the location accessible permanently?



Oops, sorry I thought I included that information, I am using the VLC phonon.
Here is the Amarok diagnostic description:
-----------------------------
Amarok Diagnostics

Amarok Version: 2.8.0
KDE Version: 4.14.2
Qt Version: 4.8.6
Phonon Version: 4.7.80
Phonon Backend: VLC (0.7.80)
PulseAudio: Yes

Amarok Scripts:
    Amarok Script Console 1.0 (stopped)
Lyricwiki .2 (running)
Free Music Charts 1.6.0 (running)
Librivox.org 1.0 (running)
Cool Streams 1.0 (running)

Amarok Plugins:
    AudioCd Collection (enabled)
DAAP Collection (enabled)
MTP Collection (enabled)
MySQLServer Collection (enabled)
MySQLe Collection (enabled)
Nepomuk Collection (disabled)
UPnP Collection (disabled)
Universal Mass Storage Collection (enabled)
iPod, iPad & iPhone Collection (enabled)
Ampache (disabled)
Jamendo (enabled)
Last.fm (enabled)
MP3 Music Store (disabled)
MP3tunes (disabled)
Magnatune Store (enabled)
Podcast Directory (enabled)
gpodder.net (disabled)
---------------------------------------------

These are not for live podcast or streams, but for rss feed episodes with permanent access. 
As far as I can tell my network is stable, I just can't figure out why it would stop randomly.

Comment 3 Myriam Schweingruber 2015-05-21 22:48:16 UTC

Please try the phonon-backend-gstreamer with at least version 4.7.80 and the gstreamer 1.x plugins

Comment 4 phillip9001 2015-05-22 01:23:13 UTC

(In reply to Myriam Schweingruber from comment #3)
> Please try the phonon-backend-gstreamer with at least version 4.7.80 and the
> gstreamer 1.x plugins

Wow, apparently that worked. I switched backends from VLC to Gstreamer; here are the specs:
----------------------------
Amarok Diagnostics

Amarok Version: 2.8.0
KDE Version: 4.14.2
Qt Version: 4.8.6
Phonon Version: 4.7.80
Phonon Backend: GStreamer (4.7.80)
PulseAudio: Yes

Amarok Scripts:
    Amarok Script Console 1.0 (stopped)
Lyricwiki .2 (running)
Free Music Charts 1.6.0 (running)
Librivox.org 1.0 (running)
Cool Streams 1.0 (running)
----------------------------------------

And none of the podcasts stopped randomly, however I did notice this new text that appeared in Konsole while I was running the "amarok -d --nofork" command:

--------------------------------
amarok:     successfuly parsed feed:  "http://feeds.feedburner.com/Volume5" 
amarok:     Finished updating:  KUrl("http://feeds.feedburner.com/Volume5") 
amarok:     Updating counter reached  0 
amarok:   [EngineController] slotMetaDataChanged() triggered by phonon, but we've already seen exactly the same metadata recently. Ignoring for now. 
------------------------------------

My best guess is that the phonon-backend-vlc wasn't allowing the podcasts to update for some reason, or perhaps that vlc backend doesn't have the code the gstreamer to work in tandem in podcast retrieval and updates.

I'm not sure if I should mark it solved or have it marked as a problem to be looked into, regarding the phonon-backend-vlc.

Comment 5 Myriam Schweingruber 2015-05-22 08:43:53 UTC

Thank you for this valuable information. I am reassigning this to the phonon-backend-vlc.

Comment 6 Harald Sitter 2015-05-22 19:10:15 UTC

We'll need debug output of the audio system as well unfortunately. If I am not mistaken you can start amarok with --debug-audio and that should enable all the necessary bits, you'll notice as the verbosity increases substantially.

Should --debug-audio not work exporting a couple of environment variables before starting amarok should do the trick:
https://techbase.kde.org/Development/Tutorials/Debugging/Phonon#Environment_Variables

Comment 7 phillip9001 2015-05-23 03:47:06 UTC

(In reply to Harald Sitter from comment #6)
> We'll need debug output of the audio system as well unfortunately. If I am
> not mistaken you can start amarok with --debug-audio and that should enable
> all the necessary bits, you'll notice as the verbosity increases
> substantially.
> 
> Should --debug-audio not work exporting a couple of environment variables
> before starting amarok should do the trick:
> https://techbase.kde.org/Development/Tutorials/Debugging/
> Phonon#Environment_Variables



Okay, so I switched back to phonon-backend-vlc, logged out and then back in.
I started Konsole and typed "amarok --debug-audio", like you asked and I started the podcast.
It repeated the same behavior again but now I might have the sufficient debuggin code you requested:
------------------------------
PHONON-VLC BEGIN: void Phonon::VLC::MediaObject::changeState(Phonon::State) 
PHONON-VLC    Phonon::BufferingState  -->  Phonon::PlayingState  
PHONON-VLC END__: void Phonon::VLC::MediaObject::changeState(Phonon::State) [Took: 0s] 
State changed from  Phonon::BufferingState  to  Phonon::PlayingState  -> sending to zeitgeist. 
State changed from  Phonon::PlayingState  to  Phonon::BufferingState  -> sending to zeitgeist. 
State changed from  Phonon::BufferingState  to  Phonon::PlayingState  -> sending to zeitgeist. 
QTimeLine::start: already running
"PulseSupport(2): Found PulseAudio stream index 10 for Phonon Output Stream {0cd64bbc-7489-430b-aa2a-a01651e9ca0c}" 
"PulseSupport(2): Found PulseAudio stream index 10 for Phonon Output Stream {0cd64bbc-7489-430b-aa2a-a01651e9ca0c}" 
Calling appendChild() on a null node does nothing.
PHONON-VLC BEGIN: void Phonon::VLC::MediaObject::updateState(Phonon::VLC::MediaPlayer::State) 
PHONON-VLC   State(MediaPlayer::EndedState) 
PHONON-VLC   attempted autoplay? false 
PHONON-VLC   BEGIN: void Phonon::VLC::MediaObject::changeState(Phonon::State) 
PHONON-VLC      Phonon::PlayingState  -->  Phonon::StoppedState  
PHONON-VLC   END__: void Phonon::VLC::MediaObject::changeState(Phonon::State) [Took: 0s] 
PHONON-VLC END__: void Phonon::VLC::MediaObject::updateState(Phonon::VLC::MediaPlayer::State) [Took: 0s] 
void Phonon::MediaObjectPrivate::_k_aboutToFinish() 
void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 5  QUrl( "" )  "" 
PHONON-VLC BEGIN: virtual void Phonon::VLC::MediaObject::stop() 
PHONON-VLC END__: virtual void Phonon::VLC::MediaObject::stop() [Took: 0s] 
PHONON-VLC BEGIN: virtual void Phonon::VLC::MediaObject::setSource(const Phonon::MediaSource&) 
PHONON-VLC   [ERROR__] virtual void Phonon::VLC::MediaObject::setSource(const Phonon::MediaSource&) MediaSource is empty. 
PHONON-VLC   Sending currentSourceChanged 
PHONON-VLC END__: virtual void Phonon::VLC::MediaObject::setSource(const Phonon::MediaSource&) [Took: 0s] 
State changed from  Phonon::PlayingState  to  Phonon::StoppedState  -> sending to zeitgeist. 
PHONON-VLC BEGIN: void Phonon::VLC::MediaObject::updateState(Phonon::VLC::MediaPlayer::State) 
PHONON-VLC   State(MediaPlayer::StoppedState) 
PHONON-VLC   attempted autoplay? false 
PHONON-VLC   BEGIN: void Phonon::VLC::MediaObject::changeState(Phonon::State) 
PHONON-VLC   END__: void Phonon::VLC::MediaObject::changeState(Phonon::State) [Took: 0s] 
PHONON-VLC END__: void Phonon::VLC::MediaObject::updateState(Phonon::VLC::MediaPlayer::State) [Took: 0s] 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
"PulseSupport(2): Phonon Output Stream {0cd64bbc-7489-430b-aa2a-a01651e9ca0c} is gone at the PA end. Marking it as invalid in our cache as we may reuse it." 
Calling appendChild() on a null node does nothing.
-------------------------------------
So the error message (around line 23) is where my podcast stopped and the timeline marker reset itself.

Let me know if you need anymore info or run debugging scripts.
Thanks.

Comment 8 Harald Sitter 2016-06-04 13:55:01 UTC

The way I it this is probably a VLC bug. Basically it thinks the track actually ended. Which might be bogus encoding or just a real bug. Not much we can do about this in Phonon or Amarok.