Bug 406701 - Some tracks not marked as played (zero length?) with vlc backend
Summary: Some tracks not marked as played (zero length?) with vlc backend
Status: RESOLVED FIXED
Alias: None
Product: amarok
Classification: Applications
Component: Playback (other bugs)
Version First Reported In: unspecified
Platform: Ubuntu Linux
: NOR normal
Target Milestone: kf5
Assignee: Amarok Bugs
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2019-04-20 11:12 UTC by robert marshall
Modified: 2024-06-19 12:28 UTC (History)
1 user (show)

See Also:
Latest Commit:
Version Fixed/Implemented In:
Sentry Crash Report:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description robert marshall 2019-04-20 11:12:57 UTC
SUMMARY

When using the vlc backend I'm seeing that some tracks I play don't get the last played updated 

STEPS TO REPRODUCE
1. Run amarok with a vlc backend
2. Track with significant length doesn't get marked has having been played after track completes - I have lastfm plugin enabled and the track doesn't get scrobbled either
3. I don't see this problem happening with the gstreamer backend
4. I suspect this is probably a backend issue but I'm putting it here in the first instance!

Selected output with amarok -d, track lenght is 74 seconds but there appears to be a multiplier by zero - not sure of the significance of this? This happens with other tracks beside this one. I also played this track with a 'stop playing  after this track' enabled and then the played time *was* updated.

amarok:         [00;32mBEGIN:[00;39m void EngineController::playUrl(const KUrl&, uint, bool) 
amarok:           [EngineController] URL:  KUrl("file:///Backup/oldroot/Backup/robert/Music/ClassicSelect/Little Big Box The Passion According To St Matthew/01-21- Chorale Erkenne mich, mein HБter.mp3") "file:///Backup/oldroot/Backup/robert/Music/ClassicSelect/Little%20Big%20Box%20The%20Passion%20According%20To%20St%20Matthew/01-21-%20Chorale%20Erkenne%20mich,%20mein%20H%D0%91ter.mp3" 
amarok:           [EngineController] Offset:  0 
amarok:         [00;32mEND__:[00;39m void EngineController::playUrl(const KUrl&, uint, bool) [00;32m[Took: 0s][00;39m 
amarok:       [00;36mEND__:[00;39m void EngineController::play(Meta::TrackPtr, uint, bool) [00;36m[Took: 0s][00;39m 
amarok:     [00;35mEND__:[00;39m void Playlist::Actions::play(quint64, bool) [00;35m[Took: 0s][00;39m 
amarok:   [00;34mEND__:[00;39m void Playlist::Actions::play(const QModelIndex&) [00;34m[Took: 0.001s][00;39m 
amarok: [00;32mEND__:[00;39m void Playlist::PrettyListView::trackActivated(const QModelIndex&) [00;32m[Took: 0.001s][00;39m 
amarok: [00;34mBEGIN:[00;39m void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) 
amarok:   [EngineController] Empty MediaSource (engine stop) 
amarok: [00;34mEND__:[00;39m void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) [00;34m[Took: 0s][00;39m 
amarok: [EngineController] slotStateChanged from  Phonon::StoppedState  to  Phonon::LoadingState  
amarok: [EngineController] slotStateChanged from  Phonon::LoadingState  to  Phonon::StoppedState  
amarok: MPRIS2: Queueing up a PropertiesChanged signal 
amarok: [00;35mBEGIN:[00;39m void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) 
amarok:   [07;33m[WARNING][00;39m [EngineController] Would use gain of -1 , but current Phonon backend doesn't seem to support pre-amplifier (VolumeFaderEffect) 
amarok:   [WikipediaEngine] Fetching langlinks: KUrl("https://en.wikipedia.org/w/api.php?action=query&prop=langlinks&titles=English%20Chamber%20Orchestra%2C%20Ambrosian%20Singers%2C%20Desborough%20Boys%20Choir%20%26%20Johannes%20Somary&format=xml&lllimit=100&redirects=1") 
amarok:   MPRIS: New location for width 600 is KUrl("file:///home/robert/.kde/share/apps/amarok/albumcovers/cache/600@21ea91481aaa599b2d77e86d0717d8f7") 
amarok:   [00;36mBEGIN:[00;39m void Playlist::Actions::slotTrackPlaying(Meta::TrackPtr) 
amarok:     [00;31mBEGIN:[00;39m void Playlist::PrettyListView::slotPlaylistActiveTrackChanged() 
amarok:     [00;31mEND__:[00;39m void Playlist::PrettyListView::slotPlaylistActiveTrackChanged() [00;31m[Took: 0s][00;39m 
amarok:   [00;36mEND__:[00;39m void Playlist::Actions::slotTrackPlaying(Meta::TrackPtr) [00;36m[Took: 0s][00;39m 
amarok:   [00;32mBEGIN:[00;39m void ProgressWidget::redrawBookmarks(const QString*) 
amarok:     found  0  timecodes on this track 
amarok:   [00;32mEND__:[00;39m void ProgressWidget::redrawBookmarks(const QString*) [00;32m[Took: 0.017s][00;39m 
amarok:   [00;34mBEGIN:[00;39m void CurrentEngine::trackPlaying(Meta::TrackPtr) 
amarok:     [CurrentEngine] updating track "Chorale: Erkenne mich, mein Hüter" 
amarok:   [00;34mEND__:[00;39m void CurrentEngine::trackPlaying(Meta::TrackPtr) [00;34m[Took: 0.004s][00;39m 
amarok:   [00;35mBEGIN:[00;39m void OSDWidget::show(const QString&, const QImage&) 
amarok:   [00;35mEND__:[00;39m void OSDWidget::show(const QString&, const QImage&) [00;35m[Took: 0.001s][00;39m 
amarok: [00;35mEND__:[00;39m void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) [00;35m[Took: 0.045s][00;39m 
amarok: [00;36mBEGIN:[00;39m void ProgressWidget::redrawBookmarks(const QString*) 
amarok:   found  0  timecodes on this track 
amarok: [00;36mEND__:[00;39m void ProgressWidget::redrawBookmarks(const QString*) [00;36m[Took: 0.01s][00;39m 
amarok: [00;31mBEGIN:[00;39m void ScriptManager::notifyFetchLyrics(const QString&, const QString&, const QString&, Meta::TrackPtr) 
amarok:   SCRIPT "LyricWiki" :  "request URL: http://lyrics.wikia.com/api.php?action=query&prop=revisions&rvprop=content&format=xml&titles=English_Chamber_Orchestra,_Ambrosian_Singers,_Desborough_Boys_Choir_&_Johannes_Somary:Chorale:_Erkenne_Mich,_Mein_Hüter" 
amarok:   [00;32mBEGIN:[00;39m static QScriptValue AmarokScript::Downloader::init(QScriptContext*, QScriptEngine*, bool) 
amarok:   [00;32mEND__:[00;39m static QScriptValue AmarokScript::Downloader::init(QScriptContext*, QScriptEngine*, bool) [00;32m[Took: 0s][00;39m 
amarok: [00;31mEND__:[00;39m void ScriptManager::notifyFetchLyrics(const QString&, const QString&, const QString&, Meta::TrackPtr) [00;31m[Took: 0.002s][00;39m 
amarok: MPRIS2: Queueing up a PropertiesChanged signal 
amarok: MPRIS2: Album image location is KUrl("amarok-sqltrackuid://58d9a85618ac362776820debe70a5b92") 
amarok: MPRIS2: New location for width 600 is KUrl("file:///home/robert/.kde/share/apps/amarok/albumcovers/cache/600@21ea91481aaa599b2d77e86d0717d8f7") 
amarok: [00;34mBEGIN:[00;39m void Amarok::MediaPlayer2Player::volumeChanged(int) 
amarok: [00;34mEND__:[00;39m void Amarok::MediaPlayer2Player::volumeChanged(int) [00;34m[Took: 0s][00;39m 
amarok: [EngineController] slotStateChanged from  Phonon::StoppedState  to  Phonon::LoadingState  
amarok: [EngineController] slotStateChanged from  Phonon::LoadingState  to  Phonon::BufferingState  
amarok: [EngineController] slotTrackLengthChanged( 74897 ) 
amarok: [00;35mBEGIN:[00;39m void ProgressWidget::redrawBookmarks(const QString*) 
amarok:   found  0  timecodes on this track 
amarok: [00;35mEND__:[00;39m void ProgressWidget::redrawBookmarks(const QString*) [00;35m[Took: 0.008s][00;39m 
amarok: MPRIS2: Album image location is KUrl("amarok-sqltrackuid://58d9a85618ac362776820debe70a5b92") 
amarok: MPRIS2: New location for width 600 is KUrl("file:///home/robert/.kde/share/apps/amarok/albumcovers/cache/600@21ea91481aaa599b2d77e86d0717d8f7") 
amarok: [EngineController] slotStateChanged from  Phonon::BufferingState  to  Phonon::PlayingState  
amarok: [EngineController] slotStateChanged from  Phonon::PlayingState  to  Phonon::BufferingState  
amarok: [EngineController] slotStateChanged from  Phonon::BufferingState  to  Phonon::PlayingState  
amarok: [NetworkAccessManagerProxy] the server is redirecting the request to:  KUrl("https://lyrics.fandom.com/api.php?action=query&prop=revisions&rvprop=content&format=xml&titles=English_Chamber_Orchestra%2C_Ambrosian_Singers%2C_Desborough_Boys_Choir_%26_Johannes_Somary:Chorale%3A_Erkenne_Mich%2C_Mein_H%C3%BCter") 
amarok: [00;36mBEGIN:[00;39m void AmarokScript::AmarokDownloadHelper::requestRedirected(const KUrl&, const KUrl&) 
amarok: [00;36mEND__:[00;39m void AmarokScript::AmarokDownloadHelper::requestRedirected(const KUrl&, const KUrl&) [00;36m[Took: 0s][00;39m 
amarok: [WikipediaEngine] Fetching listing: KUrl("https://en.wikipedia.org/w/api.php?action=query&list=search&srsearch=English%20Chamber%20Orchestra%2C%20Ambrosian%20Singers%2C%20Desborough%20Boys%20Choir%20%26%20Johannes%20Somary&srprop=size&srredirects=1&srlimit=20&format=xml") 
amarok: [00;31mBEGIN:[00;39m void WikipediaEnginePrivate::_dataContainerUpdated(const QString&, const Data&) 
amarok: [00;31mEND__:[00;39m void WikipediaEnginePrivate::_dataContainerUpdated(const QString&, const Data&) [00;31m[Took: 0s][00;39m 
amarok: [00;32mBEGIN:[00;39m void WikipediaApplet::dataUpdated(const QString&, const Data&) 
amarok: [00;32mEND__:[00;39m void WikipediaApplet::dataUpdated(const QString&, const Data&) [00;32m[Took: 0s][00;39m 
amarok: [00;34mBEGIN:[00;39m static QScriptValue AmarokScript::Downloader::init(QScriptContext*, QScriptEngine*, bool) 
amarok: [00;34mEND__:[00;39m static QScriptValue AmarokScript::Downloader::init(QScriptContext*, QScriptEngine*, bool) [00;34m[Took: 0s][00;39m 
amarok: [NetworkAccessManagerProxy] the server is redirecting the request to:  KUrl("https://lyrics.fandom.com/api.php?action=lyrics&func=getSong&fmt=xml&artist=English_Chamber_Orchestra%2C_Ambrosian_Singers%2C_Desborough_Boys_Choir_%26_Johannes_Somary&song=Chorale%3A_Erkenne_Mich%2C_Mein_H%C3%BCter") 
amarok: [00;35mBEGIN:[00;39m void AmarokScript::AmarokDownloadHelper::requestRedirected(const KUrl&, const KUrl&) 
amarok: [00;35mEND__:[00;39m void AmarokScript::AmarokDownloadHelper::requestRedirected(const KUrl&, const KUrl&) [00;35m[Took: 0s][00;39m 
amarok: [00;36mBEGIN:[00;39m void AmarokScript::AmarokLyricsScript::showLyricsNotFound(const QString&) const 
amarok:   [00;31mBEGIN:[00;39m void LyricsManager::lyricsNotFound(const QString&) 
amarok:     [00;32mBEGIN:[00;39m bool LyricsManager::showCached() 
amarok:     [00;32mEND__:[00;39m bool LyricsManager::showCached() [00;32m[Took: 0s][00;39m 
amarok:     [00;34mBEGIN:[00;39m void LyricsSubject::sendLyricsMessage(const QString&, const QString&) 
amarok:       [00;35mBEGIN:[00;39m virtual void LyricsEngine::lyricsMessage(const QString&, const QString&) 
amarok:       [00;35mEND__:[00;39m virtual void LyricsEngine::lyricsMessage(const QString&, const QString&) [00;35m[Took: 0s][00;39m 
amarok:     [00;34mEND__:[00;39m void LyricsSubject::sendLyricsMessage(const QString&, const QString&) [00;34m[Took: 0s][00;39m 
amarok:   [00;31mEND__:[00;39m void LyricsManager::lyricsNotFound(const QString&) [00;31m[Took: 0s][00;39m 
amarok: [00;36mEND__:[00;39m void AmarokScript::AmarokLyricsScript::showLyricsNotFound(const QString&) const [00;36m[Took: 0s][00;39m 
Calling appendChild() on a null node does nothing.
amarok: [lastfm] nowPlaying:  "English Chamber Orchestra, Ambrosian Singers, Desborough Boys Choir & Johannes Somary" - "Little Big Box :: The Passion According To St. Matthew" - "Chorale: Erkenne mich, mein Hüter" source: 2 duration: 74 
"  <lfm status="ok">
    <nowplaying>
      <track corrected="0">Chorale: Erkenne mich, mein Hüter</track>
      <artist corrected="0">English Chamber Orchestra, Ambrosian Singers, Desborough Boys Choir &amp; Johannes Somary</artist>
      <album corrected="0">Little Big Box :: The Passion According To St. Matthew</album>
      <albumArtist corrected="0">Various artists</albumArtist>
      <ignoredMessage code="0"/>
    </nowplaying>
  </lfm>
" 
QTimeLine::start: already running
amarok: [CollectionTreeView] Got custom action:  "Display Cover" 
amarok: [CollectionTreeView] Got custom action:  "Fetch Cover" 
amarok: [CollectionTreeView] Got custom action:  "Set Custom Cover" 
amarok: [CollectionTreeView] Got custom action:  "Unset Cover" 
amarok: [CollectionTreeView] Got custom action:  "" 
amarok: [CollectionTreeView] Got custom action:  "Show under Various Artists" 
amarok: [CollectionTreeView] checking for global actions 
amarok: [CollectionViewScript] Checking for scripted actions 
amarok: [00;36mBEGIN:[00;39m void Playlist::Controller::insertOptioned(Meta::TrackList, Playlist::AddOptions) 
amarok:   [00;31mBEGIN:[00;39m virtual void Playlist::InsertTracksCmd::redo() 
amarok:     [00;32mBEGIN:[00;39m void Playlist::Model::setAllNewlyAddedToUnplayed() 
amarok:     [00;32mEND__:[00;39m void Playlist::Model::setAllNewlyAddedToUnplayed() [00;32m[Took: 0s][00;39m 
amarok:     MPRIS2: Queueing up a PropertiesChanged signal 
amarok:   [00;31mEND__:[00;39m virtual void Playlist::InsertTracksCmd::redo() [00;31m[Took: 0.001s][00;39m 
amarok: [00;36mEND__:[00;39m void Playlist::Controller::insertOptioned(Meta::TrackList, Playlist::AddOptions) [00;36m[Took: 0.001s][00;39m 
amarok: [CollectionTreeView] Got custom action:  "Display Cover" 
amarok: [CollectionTreeView] Got custom action:  "Fetch Cover" 
amarok: [CollectionTreeView] Got custom action:  "Set Custom Cover" 
amarok: [CollectionTreeView] Got custom action:  "Unset Cover" 
amarok: [CollectionTreeView] Got custom action:  "" 
amarok: [CollectionTreeView] Got custom action:  "Show under Various Artists" 
amarok: [CollectionTreeView] checking for global actions 
amarok: [CollectionViewScript] Checking for scripted actions 
Calling appendChild() on a null node does nothing.
amarok: [00;34mBEGIN:[00;39m TagDialog::TagDialog(Collections::QueryMaker*) 
amarok: [00;34mEND__:[00;39m TagDialog::TagDialog(Collections::QueryMaker*) [00;34m[Took: 0.025s][00;39m 
amarok: [00;35mBEGIN:[00;39m void TagDialog::initUi() 
amarok:   [TagDialog] setPerTrack 78 false 
amarok: [00;35mEND__:[00;39m void TagDialog::initUi() [00;35m[Took: 0.007s][00;39m 
amarok: [00;36mBEGIN:[00;39m void TagDialog::updateCover() 
amarok: [00;36mEND__:[00;39m void TagDialog::updateCover() [00;36m[Took: 0.001s][00;39m 
amarok: [SqlRegistry]   albums: 43 (-3054) of 3098 cached 
amarok: [SqlRegistry]  artists: 73 (-4036) of 4110 cached 
amarok: [SqlRegistry]   genres: 11 (-171) of 183 cached 
amarok: [SqlRegistry]   tracks: 165 (-1076) of 26893 cached 
amarok: [00;31mBEGIN:[00;39m virtual TagDialog::~TagDialog() 
amarok: [00;31mEND__:[00;39m virtual TagDialog::~TagDialog() [00;31m[Took: 0s][00;39m 
QTimeLine::start: already running
amarok: [00;32mBEGIN:[00;39m void EngineController::slotAboutToFinish() 
amarok:   [00;34mBEGIN:[00;39m void Playlist::Actions::requestNextTrack() 
amarok:     [00;35mBEGIN:[00;39m void Playlist::Actions::play(quint64, bool) 
amarok:       [00;36mBEGIN:[00;39m void EngineController::setNextTrack(Meta::TrackPtr) 
amarok:         [00;31mBEGIN:[00;39m void EngineController::play(Meta::TrackPtr, uint, bool) 
amarok:           [00;32mBEGIN:[00;39m void EngineController::stop(bool, bool) 
amarok:             [EngineController] slotTrackFinishedPlaying( "English Chamber Orchestra, Ambrosian Singers, Desborough Boys Choir & Johannes Somary" - "Little Big Box :: The Passion According To St. Matthew" - "Chorale: Erkenne mich, mein Hüter" , 0 ) 
amarok:             [lastfm] scrobble(): refusing track "/Backup/oldroot/Backup/robert/Music/ClassicSelect/Little Big Box The Passion According To St Matthew/01-21- Chorale Erkenne mich, mein HБter.mp3" - played time ( 74 * 0 s) shorter than 30 s 
amarok:           [00;32mEND__:[00;39m void EngineController::stop(bool, bool) [00;32m[Took: 0.006s][00;39m 
amarok:           [EngineController] play: bounded is  QObject(0x0)  current "Finale (Bewegt, doch nicht schnell)" 

I can provide the complete session output if required (3500 lines)


SOFTWARE/OS VERSIONS
Windows: 
macOS: 
Linux/KDE Plasma: 4.14.38
(available in About System)
KDE Plasma Version: 
KDE Frameworks Version: 
Qt Version: 

ADDITIONAL INFORMATION

amarok 2.9.0 but from git and the 2.9  branch
Comment 1 robert marshall 2024-04-16 14:41:04 UTC
I'm still seeing this one with 2.9.83 - my suspicion is that's it's UTF-8 related though a track with the title "Winterreise op. 89, D. 911: Täuschung"
works but the one in the original bug report  "Chorale: Erkenne mich, mein Hüter" doesn't?
Comment 2 Tuomas Nurmi 2024-06-19 12:28:42 UTC
Git commit e3dd77951ea229a183b3e246ad29db0747c76e4a by Tuomas Nurmi.
Committed on 19/06/2024 at 12:18.
Pushed by nurmi into branch 'master'.

Use our own progress for track if phonon reported position seems wrong

At least phonon-vlc seems to commonly claim position is 0 when stopping
playback / when backend prepares the next track to be played gapless. This
causes the track progress on stop to be 0, which further causes the track
scrobbling and playcount updates get skipped (at least sometimes), it seems.
Related: bug 337849

M  +2    -0    ChangeLog
M  +7    -1    src/EngineController.cpp

https://invent.kde.org/multimedia/amarok/-/commit/e3dd77951ea229a183b3e246ad29db0747c76e4a