Bug 269544

Summary:	Amarok-2.4.0: m3u playlists stop after each file
Product:	[Applications] amarok	Reporter:	svenvermant
Component:	general	Assignee:	Amarok Bugs <amarok-bugs-null>
Status:	RESOLVED WORKSFORME
Severity:	normal	CC:	bcooksley, dilfridge, fabo, jb, martin.sandsmark, myriam, nhn, teo
Priority:	NOR
Version First Reported In:	unspecified
Target Milestone:	---
Platform:	Gentoo Packages
OS:	Linux
Latest Commit:		Version Fixed/Implemented In:	2.5
Sentry Crash Report:
Attachments:	log for phonon-vlc-0.4.0

Description svenvermant 2011-03-27 15:30:26 UTC

Version:           2.4.0 (using KDE 4.6.1) 
OS:                Linux

I use to have a single m3u file (generated by amarok) in each directory of my
music collection (contains only ogg files), for an example see below. Amarok
recognizes all these files in the collection and lists them correctly as
playlists on the hard drive. However, when I playback one of these lists, one
ogg file gets played and then the playback gets stopped. I can then manually
restart playback and experience the next stop after finishing the next track
and so on. Strangely, if I add the same playlist manually by drag and drop from
dolphin, all files are played nicely one after the other. Does anybody have a
clue what is going wrong here?

#EXTM3U
#EXTINF:267000,Sonata a 12
./1-01 - Sonata a 12.ogg
#EXTINF:304000,Deus in audiutrium meum/Domine ad adiuvandum
./1-02 - Deus in audiutrium meum_Domine ad adiuvandum.ogg
#EXTINF:665000,Assumpta est Maria/Dixit Dominus
./1-03 - Assumpta est Maria_Dixit Dominus.ogg
#EXTINF:1027000,Maria Virgo Assumpta est/Laudate pueri
./1-04 - Maria Virgo Assumpta est_Laudate pueri.ogg
#EXTINF:338000,In odorem unguentorum/Laetatus sum
./1-05 - In odorem unguentorum_Laetatus sum.ogg
#EXTINF:661000,Benedicta filia tua/Nisi Dominus
./2-01 - Benedicta filia tua_Nisi Dominus.ogg
#EXTINF:356000,O Laeta dies
./2-02 - O Laeta dies.ogg
#EXTINF:435000,Pulchra es/Lauda Jerusalem
./2-03 - Pulchra es_Lauda Jerusalem.ogg
#EXTINF:213000,del Buono, G. P. / Ave maris Stella
./2-04 - del Buono, G. P. _ Ave maris Stella.ogg
#EXTINF:121000,del Buono, G. P. / Ave maris Stella
./2-05 - del Buono, G. P. _ Ave maris Stella.ogg
#EXTINF:906000,Hodie Maria/Magnificat
./2-06 - Hodie Maria_Magnificat.ogg

I noticed that the problem does not occur with very old playlists which
differ from the newer ones only by the fact that the time after #EXTINF: is
given in seconds and not in miliseconds.

Reproducible: Always

Steps to Reproduce:
1.) Add playlist from the collection to the current playlist.
2.) Start playing songs.

Actual Results:  
After the first song is finished, the playlist advances to the next piece, but playback is actually stopped and has to be continued manually. This hapens with all pieces of the list.

Expected Results:  
Amarok should play one piece from the list after the other until the end of the list is reached.

emerge --info
Portage 2.2.0_alpha28 (default/linux/x86/10.0, gcc-4.4.5, glibc-2.11.3-r0,
2.6.36-tuxonice-r3 i686)
=================================================================
System uname:
Linux-2.6.36-tuxonice-r3-i686-Intel-R-_Core-TM-2_Duo_CPU_T7300_@_2.00GHz-with-gentoo-1.12.14
Timestamp of tree: Sat, 26 Mar 2011 07:30:01 +0000
ccache version 2.4 [disabled]
app-shells/bash:     4.1_p9
dev-java/java-config: 2.1.11-r3
dev-lang/python:     2.6.6-r2, 3.1.3-r1
dev-util/ccache:     2.4-r9
dev-util/cmake:      2.8.1-r2
sys-apps/baselayout: 1.12.14-r1
sys-apps/sandbox:    2.4
sys-devel/autoconf:  2.13, 2.65-r1
sys-devel/automake:  1.9.6-r3, 1.10.3, 1.11.1
sys-devel/binutils:  2.20.1-r1
sys-devel/gcc:       4.4.5
sys-devel/gcc-config: 1.4.1
sys-devel/libtool:   2.2.10
sys-devel/make:      3.81-r2
virtual/os-headers:  2.6.36.1 (sys-kernel/linux-headers)
Repositories: gentoo astronomy kde local-overlay
Installed sets: @kde-4.6, @system
ACCEPT_KEYWORDS="x86"
ACCEPT_LICENSE="*"
CBUILD="i686-pc-linux-gnu"
CFLAGS="-march=native -O2 -pipe -fomit-frame-pointer"
CHOST="i686-pc-linux-gnu"
CONFIG_PROTECT="/etc /usr/kde/3.5/env /usr/kde/3.5/share/config
/usr/kde/3.5/shutdown /usr/share/config /usr/share/gnupg/qualified.txt
/var/lib/hsqldb"
CONFIG_PROTECT_MASK="/etc/ca-certificates.conf /etc/env.d /etc/env.d/java/
/etc/fonts/fonts.conf /etc/gconf /etc/revdep-rebuild /etc/sandbox.d /etc/splash
/etc/terminfo /etc/texmf/language.dat.d /etc/texmf/language.def.d
/etc/texmf/updmap.d /etc/texmf/web2c"
CXXFLAGS="-march=native -O2 -pipe -fomit-frame-pointer"
DISTDIR="/usr/portage/distfiles"
FEATURES="assume-digests binpkg-logs distlocks fixlafiles fixpackages news
parallel-fetch protect-owned sandbox sfperms strict unknown-features-warn
unmerge-logs unmerge-orphans userfetch"
FFLAGS=""
GENTOO_MIRRORS="http://linux.rz.ruhr-uni-bochum.de/download/gentoo-mirror/"
LANG="de_DE.utf-8"
LC_ALL="de_DE.utf-8"
LDFLAGS="-Wl,-O1 -Wl,--as-needed"
LINGUAS="de"
MAKEOPTS="-j3"
PKGDIR="/usr/portage/packages"
PORTAGE_CONFIGROOT="/"
PORTAGE_RSYNC_OPTS="--recursive --links --safe-links --perms --times --compress
--force --whole-file --delete --stats --timeout=180 --exclude=/distfiles
--exclude=/local --exclude=/packages"
PORTAGE_TMPDIR="/var/tmp"
PORTDIR="/usr/portage"
PORTDIR_OVERLAY="/var/lib/layman/astronomy /var/lib/layman/kde
/usr/local/portage"
SYNC="rsync://rsync.gentoo.org/gentoo-portage"
USE="#-redland X aac accessibility acl acpi addbookmarks alias alsa archive
autoreplace avahi bash-completion beagle berkdb bzip2 cairo cdaudio chm cli
clucene connectionstatus consolekit contactnotes context cracklib crypt cuda
cups cxx daemon dbus deprecated djvu dri dvd dvdr dvipdfm enblend encode exif
extra facebook fam fbcon fbcondecor ffmpeg fftw flac fortran fts3 gdbm geoip
gif glib gnuplot gpm graphics gsl gstreamer iconv icq imagemagick inotify ipv6
ipw4965 ipython jabber java java5 jpeg jpeg2k kde kipi kontact kpathsea laptop
latex ldap lm_sensors mac mdnsresponder-compat messenger mikmod mmx mng modules
mono mp3 mp4 mpeg msn mudflap musepack musicbrainz mysql ncurses nepomuk nls
npp nptl nptlonly nsplugin nvidia offensive ogg old-daemons opengl openmp oscar
pam pcre pdf perl plasma plotutils png policykit postscript pppd pstricks
publishers python qq qt qt3 qt3support qt4 readline resolvconf sasl science
semantic-desktop sesame2 session sift spell sse sse2 ssl ssse3 svg symlink
sysfs tcpd threads thunderbird tiff tk truetype udev unicode userlocales
utempter v4l v4l2 vdpau virtuoso vorbis wavpack webkit wifi win32codecs wlm x86
xcomposite xorg xscreensaver xulrunner yahoo zeroconf zip zlib"
ALSA_CARDS="ali5451 als4000 atiixp atiixp-modem bt87x ca0106 cmipci emu10k1
emu10k1x ens1370 ens1371 es1938 es1968 fm801 hda-intel intel8x0 intel8x0m
maestro3 trident usb-audio via82xx via82xx-modem ymfpci"
ALSA_PCM_PLUGINS="adpcm alaw asym copy dmix dshare dsnoop empty extplug file
hooks iec958 ioplug ladspa lfloat linear meter mmap_emul mulaw multi null plug
rate route share shm softvol" APACHE2_MODULES="actions alias auth_basic
authn_alias authn_anon authn_dbm authn_default authn_file authz_dbm
authz_default authz_groupfile authz_host authz_owner authz_user autoindex cache
cgi cgid dav dav_fs dav_lock deflate dir disk_cache env expires ext_filter
file_cache filter headers include info log_config logio mem_cache mime
mime_magic negotiation rewrite setenvif speling status unique_id userdir
usertrack vhost_alias" CAMERAS="ptp2 canon" COLLECTD_PLUGINS="df interface irq
load memory rrdtool swap syslog" ELIBC="glibc" GPSD_PROTOCOLS="ashtech aivdm
earthmate evermore fv18 garmin garmintxt gpsclock itrax mtk3301 nmea ntrip
navcom oceanserver oldstyle oncore rtcm104v2 rtcm104v3 sirf superstar2 timing
tsip tripmate tnt ubx" INPUT_DEVICES="evdev keyboard mouse synaptics"
KERNEL="linux" LCD_DEVICES="bayrad cfontz cfontz633 glk hd44780 lb216 lcdm001
mtxorb ncurses text" LINGUAS="de" PHP_TARGETS="php5-3" RUBY_TARGETS="ruby18"
USERLAND="GNU" VIDEO_CARDS="vga nvidia" XTABLES_ADDONS="quota2 psd pknock lscan
length2 ipv4options ipset ipp2p iface geoip fuzzy condition tee tarpit sysrq
steal rawnat logmark ipmark dhcpmac delude chaos account" 
Unset:  CPPFLAGS, CTARGET, EMERGE_DEFAULT_OPTS, INSTALL_MASK,
PORTAGE_BUNZIP2_COMMAND, PORTAGE_COMPRESS, PORTAGE_COMPRESS_FLAGS,
PORTAGE_RSYNC_EXTRA_OPTS

qlist -Iv phonon
kde-base/phonon-kde-4.6.1
media-sound/phonon-4.4.4
media-sound/phonon-gstreamer-4.4.4
media-sound/phonon-vlc-0.3.2

I use the GStreamer phonon backend.

Comment 1 Bart Cerneels 2011-03-30 17:03:14 UTC

Playback is not related to save playlists.
Try to change your phonon backend. vlc and xine are recommended, in that order.

The milliseconds vs. seconds might point to a difference in the tracks or encoding.

Comment 2 svenvermant 2011-03-30 21:23:17 UTC

(In reply to comment #1)
> Playback is not related to save playlists.
> Try to change your phonon backend. vlc and xine are recommended, in that order.
> 
> The milliseconds vs. seconds might point to a difference in the tracks or
> encoding.

I changed to vlc with the result that I had no sound at all. I then switched to xine which gives sound and advances in the playlist. However, it jumps ahead to much and leaves out one or the othe piece completely which is also completely satisfying.

Comment 3 Myriam Schweingruber 2011-03-31 11:39:26 UTC

(In reply to comment #2)
> (In reply to comment #1)
> > Playback is not related to save playlists.
> > Try to change your phonon backend. vlc and xine are recommended, in that order.
> > 
> > The milliseconds vs. seconds might point to a difference in the tracks or
> > encoding.
> 
> I changed to vlc with the result that I had no sound at all. 

Reassigning to Phonon. No sound at all with the vlc backend might be a verion problem, please check which phonon-backend-vlc and which libvlc version you use.

> I then switched to
> xine which gives sound and advances in the playlist. However, it jumps ahead to
> much and leaves out one or the othe piece completely which is also completely
> satisfying.

You mean completely unsatisfying I guess, don't you?

Comment 4 svenvermant 2011-03-31 13:05:35 UTC

(In reply to comment #3)
> (In reply to comment #2)
> > (In reply to comment #1)
> > > Playback is not related to save playlists.
> > > Try to change your phonon backend. vlc and xine are recommended, in that order.
> > > 
> > > The milliseconds vs. seconds might point to a difference in the tracks or
> > > encoding.
> > 
> > I changed to vlc with the result that I had no sound at all. 
> 
> Reassigning to Phonon. No sound at all with the vlc backend might be a verion
> problem, please check which phonon-backend-vlc and which libvlc version you
> use.

The problem with vlc is solved, I think it was just some temporary failure. However, with both xine and vlc backend I experience the jumping over pieces (where vlc seems to leave out every second piece while xine seems to make bigger jumps).

> > I then switched to
> > xine which gives sound and advances in the playlist. However, it jumps ahead to
> > much and leaves out one or the othe piece completely which is also completely
> > satisfying.
> 
> You mean completely unsatisfying I guess, don't you?

Ups, sure :)

Comment 5 Myriam Schweingruber 2011-04-27 21:34:10 UTC

Reassigning to the new bugzilla product for better bug tracing of the various
backends. Sorry for the noise.

Comment 6 Harald Sitter 2011-04-28 10:04:35 UTC

While we are at it.

A debug log would be super useful for VLC:
http://techbase.kde.org/Development/Tutorials/Debugging/Phonon

Comment 7 svenvermant 2011-04-28 11:15:25 UTC

Here is a debug for the VLC jumping behaviour:

void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 5  QUrl( "" )  "" 
setSource 
setSource Error: MediaSource is empty. 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 0  QUrl( "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg" )  "" 
setSource 
setSource yeap, 'tis a local file or url "file" 
stateChangedInternal newState: "BufferingState" previousState: "StoppedState" 
loadMediaInternal "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg" 
stateChangedInternal newState: "StoppedState" previousState: "BufferingState" 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
play 
Metadata ready, sending to zeitgeist 
[0x8efc6b4] main input debug: Creating an input for '35 - Track35.ogg'
[0x8efc6b4] main input debug: thread (input) created at priority 10 (input/input.c:220)
stateChangedInternal newState: "PlayingState" previousState: "StoppedState" 
updateVolume Volume changed to -  29  From  29 
State changed from 1 to 3 -> sending to zeitgeist. 
State changed from 3 to 1 -> sending to zeitgeist. 
[0x94d963c] main input debug: Creating an input for '35 - Track35.ogg'
[0x8efc6b4] main input debug: thread started
[0x8efc6b4] main input debug: using timeshift granularity of 50 MiB
[0x8efc6b4] main input debug: using timeshift path '/tmp'
[0x8efc6b4] main input debug: `file:///home/bjoern/Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/35%20-%20Track35.ogg' gives access `file' demux `' path `/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg'
[0x8efc6b4] main input debug: creating demux: access='file' demux='' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg'
[0x831b86c] main playlist debug: no fetch required for (null) (art currently (null))
[0x94de504] main demux debug: looking for access_demux module: 4 candidates
[0x94de504] main demux debug: no access_demux module matching "file" could be loaded
[0x8efc6b4] main input debug: creating access 'file' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg'
[0x8ee3f5c] main access debug: looking for access module: 4 candidates
[0x8ee3f5c] filesystem access debug: opening file `/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg'
[0x8ee3f5c] main access debug: using access module "filesystem"
[0x8ee403c] main stream debug: Using AStream*Stream
[0x8ee403c] main stream debug: pre buffering
[0x8ee403c] main stream debug: received first data after 0 ms
[0x8ee403c] main stream debug: pre-buffering done 1024 bytes in 0s - 52631 KiB/s
[0x93ed39c] main stream debug: looking for stream_filter module: 10 candidates
[0x93ed39c] main stream debug: no stream_filter module matching "any" could be loaded
[0x93ed2cc] main stream debug: looking for stream_filter module: 2 candidates
[0x93ed2cc] main stream debug: using stream_filter module "stream_filter_record"
[0x8efc6b4] main input debug: creating demux: access='file' demux='' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg'
[0x93ed3f4] main demux debug: looking for demux module: 96 candidates
[0x93ed3f4] main demux debug: using demux module "ogg"
[0x8efc6b4] main input debug: looking for a subtitle file in /home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/
[0x94df604] main demux meta debug: looking for meta reader module: 0 candidates
[0x94df604] main demux meta debug: no meta reader module matched "any"
[0x8efc6b4] main input debug: `file:///home/bjoern/Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/35%20-%20Track35.ogg' successfully opened
[0x93ed3f4] ogg demux debug: found vorbis header
[0x8efc6b4] main input debug: selecting program id=0
[0x94df114] main decoder debug: looking for decoder module: 52 candidates
[0x94df114] main decoder debug: using decoder module "vorbis"
[0x94df114] main decoder debug: thread (decoder) created at priority 5 (input/decoder.c:301)
[0x94df114] main decoder debug: thread started
[0x93ed3f4] ogg demux debug: beginning of a group of logical streams
[0x8efc6b4] main input debug: ES_OUT_RESET_PCR called
[0x94df114] main decoder debug: removing module "vorbis"
[0x94df114] main decoder debug: killing decoder fourcc `vorb', 0 PES in FIFO
[0x94df114] main decoder debug: looking for decoder module: 52 candidates
[0x94df114] main decoder debug: using decoder module "vorbis"
[0x94df114] main decoder debug: thread (decoder) created at priority 5 (input/decoder.c:301)
[0x94df114] main decoder debug: thread started
[0x94df114] vorbis decoder debug: channels:2 samplerate:44100 bitrate:192000
[0x8efc6b4] main input debug: Buffering 0%
[0x8efc6b4] main input debug: Buffering 52%
[0x8efc6b4] main input debug: Stream buffering done (390 ms in 0 ms)
[0x8efc6b4] main input debug: reusing aout
[0x93a5134] main audio output debug: looking for audio output module: 4 candidates
State changed from 1 to 2 -> sending to zeitgeist. 
[0x93a5134] alsa audio output debug: opening ALSA device `default'
[0x93a5134] main audio output debug: using audio output module "alsa"
[0x93a5134] main audio output debug: output 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0x93a5134] main audio output debug: mixer 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0x93a5134] main audio output debug: no need for any filter
[0x94d87ac] main generic debug: looking for audio mixer module: 6 candidates
[0x94d87ac] main generic debug: using audio mixer module "float32_mixer"
[0x93a5134] main audio output debug: input 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0x95ebdfc] main audio filter debug: looking for audio filter module: 2 candidates
[0x95ebdfc] scaletempo audio filter debug: format: 44100 rate, 2 nch, 4 bps, fl32
[0x95ebdfc] scaletempo audio filter debug: params: 30 stride, 0.200 overlap, 14 search
[0x95ebdfc] scaletempo audio filter debug: 1.000 scale, 1323.000 stride_in, 1323 stride_out, 1059 standing, 264 overlap, 617 search, 2204 queue, fl32 mode
[0x95ebdfc] main audio filter debug: using audio filter module "scaletempo"
[0x93a5134] main audio output debug: filter(s) 'f32l'->'f32l' 48510 Hz->44100 Hz Stereo->Stereo
[0x960f704] main audio filter debug: looking for audio filter module: 22 candidates
[0x960f704] main audio filter debug: using audio filter module "ugly_resampler"
[0x93a5134] main audio output debug: found a filter for the whole conversion
[0x94df114] main decoder debug: End of audio preroll
[0x8efc6b4] main input debug: Decoder buffering done in 9 ms
[0x93a5134] main audio output warning: PTS is out of range (-9974), dropping buffer
[0x93a5134] main audio output warning: PTS is out of range (-23015), dropping buffer
Metadata ready, sending to zeitgeist 
stateChangedInternal newState: "PlayingState" previousState: "PlayingState" 
updateDuration Length changing from  -1  to  26841 
stateChangedInternal newState: "PlayingState" previousState: "PlayingState" 
void Phonon::MediaObjectPrivate::_k_aboutToFinish() 
setNextSource 
[0x93ed3f4] ogg demux debug: end of a group of logical streams
[0x93ed3f4] ogg demux warning: couldn't find any ogg logical stream
[0x8efc6b4] main input debug: EOF reached
setSource 
setSource yeap, 'tis a local file or url "file" 
stateChangedInternal newState: "BufferingState" previousState: "PlayingState" 
stateChangedInternal no-op gapless item awaiting in queue -  1 
loadMediaInternal "file:Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/./36 - Track36.ogg" 
stateChangedInternal newState: "StoppedState" previousState: "PlayingState" 
stateChangedInternal no-op gapless item awaiting in queue -  1 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
[0x94df114] main decoder debug: removing module "vorbis"
[0x94df114] main decoder debug: killing decoder fourcc `vorb', 0 PES in FIFO
[0x95ebdfc] main audio filter debug: removing module "scaletempo"
[0x960f704] main audio filter debug: removing module "ugly_resampler"
[0x93a5134] main audio output debug: removing module "alsa"
[0x94d87ac] main generic debug: removing module "float32_mixer"
[0x8efc6b4] main input debug: releasing aout
[0x8efc6b4] main input debug: Program doesn't contain anymore ES
[0x93ed3f4] main demux debug: removing module "ogg"
[0x93ed2cc] main stream debug: removing module "stream_filter_record"
[0x8ee3f5c] main access debug: removing module "filesystem"
[0x8efc6b4] main input debug: thread ended
play 
Metadata ready, sending to zeitgeist 
[0x8efc6b4] main input debug: Creating an input for '36 - Track36.ogg'
[0x8efc6b4] main input debug: thread (input) created at priority 10 (input/input.c:220)
stateChangedInternal newState: "PlayingState" previousState: "PlayingState" 
updateVolume Volume changed to -  29  From  29 
[0x8efc6b4] main input debug: thread started
[0x8efc6b4] main input debug: using timeshift granularity of 50 MiB
[0x8efc6b4] main input debug: using timeshift path '/tmp'
[0x8efc6b4] main input debug: `file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg' gives access `' demux `' path `file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg'
[0x8efc6b4] main input debug: creating demux: access='' demux='' path='file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg'
[0x8ee2abc] main demux debug: looking for access_demux module: 12 candidates
libdvdnav: Using dvdnav version 4.1.3
[0x961d1d4] main input debug: Creating an input for '36 - Track36.ogg'
[0x831b86c] main playlist debug: no fetch required for (null) (art currently (null))
libdvdread: Using libdvdcss version 1.2.10 for DVD access
libdvdread: Could not open file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg with libdvdcss.
libdvdread: Can't open file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg for reading
libdvdnav: vm: failed to open/read the DVD
[0x8ee2abc] dvdnav demux warning: cannot open DVD (file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg)
libdvdnav: Using dvdnav version 4.1.3
libdvdread: Using libdvdcss version 1.2.10 for DVD access
libdvdread: Could not open file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg with libdvdcss.
libdvdread: Can't open file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg for reading
libdvdnav: vm: failed to open/read the DVD
[0x8ee2abc] dvdnav demux warning: cannot open DVD (file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg)
[0x8ee2abc] main demux debug: no access_demux module matching "any" could be loaded
[0x8efc6b4] main input debug: creating access '' path='file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg'
[0x93aa174] main access debug: looking for access module: 6 candidates
[0x93aa174] filesystem access debug: opening file `file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg'
[0x93aa174] filesystem access error: cannot open file file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg (No such file or directory)                                                                                                                                  
[0x93aa174] main access error: Einlesen der Datei fehlgeschlagen
[0x93aa174] main access error: VLC konnte die Datei "file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg" nicht lesen.                                                                                                                                                 
[0x93aa174] filesystem access debug: opening file `file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg'
[0x93aa174] filesystem access error: cannot open file file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg (No such file or directory)                                                                                                                                  
[0x93aa174] main access error: Einlesen der Datei fehlgeschlagen
[0x93aa174] main access error: VLC konnte die Datei "file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg" nicht lesen.                                                                                                                                                 
[0x93aa174] main access debug: no access module matching "any" could be loaded
[0x8efc6b4] main input error: open of `file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg' failed: (null)
[0x8efc6b4] main input error: Ihre Eingabe konnte nicht geöffnet werden
[0x8efc6b4] main input error: VLC kann die MRL 'file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg' nicht öffnen. Sehen Sie für Details im Fehlerprotokoll nach.                                                                                                      
[0x8efc6b4] main input debug: thread ended
void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 5  QUrl( "" )  "" 
stateChangedInternal newState: "StoppedState" previousState: "PlayingState" 
stateChangedInternal newState: "StoppedState" previousState: "StoppedState" 
setSource 
setSource Error: MediaSource is empty. 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
stateChangedInternal newState: "ErrorState" previousState: "StoppedState" 
State changed from 2 to 1 -> sending to zeitgeist. 
State changed from 1 to 5 -> sending to zeitgeist. 
"PVLC(2): Object: Phonon::VLC::AudioOutput" 
"PVLC(2): Object: Phonon::VLC::VLCMediaObject" 
"PVLC(2): Object: Phonon::VLC::AudioOutput" 
"PVLC(2): Object: Phonon::VLC::VLCMediaObject" 
emitting a state change because the backend object has been replaced 
"PVLC(2): Object: Phonon::VLC::VLCMediaObject" 
"PVLC(2): Object: Phonon::VLC::AudioOutput" 
"PVLC(2): Backend connected Phonon::VLC::VLCMediaObject to Phonon::VLC::AudioOutput" 
"PVLC(2): Object: Phonon::VLC::VLCMediaObject" 
"PVLC(2): Object: Phonon::VLC::AudioOutput" 
void Phonon::FrontendInterfacePrivate::_backendObjectChanged() 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 5  QUrl( "" )  "" 
setSource 
setSource Error: MediaSource is empty. 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 0  QUrl( "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg" )  "" 
setSource 
setSource yeap, 'tis a local file or url "file" 
stateChangedInternal newState: "BufferingState" previousState: "StoppedState" 
loadMediaInternal "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg" 
stateChangedInternal newState: "StoppedState" previousState: "BufferingState" 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
play 
Metadata ready, sending to zeitgeist 
[0x8efc6b4] main input debug: Creating an input for '37 - Track37.ogg'
[0x8efc6b4] main input debug: thread (input) created at priority 10 (input/input.c:220)
stateChangedInternal newState: "PlayingState" previousState: "StoppedState" 
updateVolume Volume changed to -  50  From  29 
[0x82eb364] main input debug: Creating an input for '37 - Track37.ogg'
[0x831b86c] main playlist debug: no fetch required for (null) (art currently (null))
[0x8efc6b4] main input debug: thread started
[0x8efc6b4] main input debug: using timeshift granularity of 50 MiB
[0x8efc6b4] main input debug: using timeshift path '/tmp'
[0x8efc6b4] main input debug: `file:///home/bjoern/Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/37%20-%20Track37.ogg' gives access `file' demux `' path `/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg'
[0x8efc6b4] main input debug: creating demux: access='file' demux='' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg'
[0x8e6e8a4] main demux debug: looking for access_demux module: 4 candidates
State changed from 1 to 3 -> sending to zeitgeist. 
[0x8e6e8a4] main demux debug: no access_demux module matching "file" could be loaded
[0x8efc6b4] main input debug: creating access 'file' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg'
[0x8edf9e4] main access debug: looking for access module: 4 candidates
[0x8edf9e4] filesystem access debug: opening file `/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg'
[0x8edf9e4] main access debug: using access module "filesystem"
[0x940b88c] main stream debug: Using AStream*Stream
[0x940b88c] main stream debug: pre buffering
[0x940b88c] main stream debug: received first data after 0 ms
[0x940b88c] main stream debug: pre-buffering done 1024 bytes in 0s - 52631 KiB/s
[0x8fccddc] main stream debug: looking for stream_filter module: 10 candidates
[0x8fccddc] main stream debug: no stream_filter module matching "any" could be loaded
[0x93a5234] main stream debug: looking for stream_filter module: 2 candidates
[0x93a5234] main stream debug: using stream_filter module "stream_filter_record"
[0x8efc6b4] main input debug: creating demux: access='file' demux='' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg'
[0x8fccddc] main demux debug: looking for demux module: 96 candidates
[0x8fccddc] main demux debug: using demux module "ogg"
[0x8efc6b4] main input debug: looking for a subtitle file in /home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/
[0x8fccf0c] main demux meta debug: looking for meta reader module: 0 candidates
[0x8fccf0c] main demux meta debug: no meta reader module matched "any"
[0x8efc6b4] main input debug: `file:///home/bjoern/Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/37%20-%20Track37.ogg' successfully opened
[0x8fccddc] ogg demux debug: found vorbis header
[0x8efc6b4] main input debug: selecting program id=0
[0x8ff740c] main decoder debug: looking for decoder module: 52 candidates
[0x8ff740c] main decoder debug: using decoder module "vorbis"
[0x8ff740c] main decoder debug: thread (decoder) created at priority 5 (input/decoder.c:301)
State changed from 3 to 1 -> sending to zeitgeist. 
State changed from 1 to 2 -> sending to zeitgeist. 
[0x8ff740c] main decoder debug: thread started
[0x8fccddc] ogg demux debug: beginning of a group of logical streams
[0x8efc6b4] main input debug: ES_OUT_RESET_PCR called
[0x8ff740c] main decoder debug: removing module "vorbis"
[0x8ff740c] main decoder debug: killing decoder fourcc `vorb', 0 PES in FIFO
[0x8ff740c] main decoder debug: looking for decoder module: 52 candidates
[0x8ff740c] main decoder debug: using decoder module "vorbis"
[0x8ff740c] main decoder debug: thread (decoder) created at priority 5 (input/decoder.c:301)
[0x8ff740c] main decoder debug: thread started
[0x8ff740c] vorbis decoder debug: channels:2 samplerate:44100 bitrate:192000
[0x8efc6b4] main input debug: Buffering 0%
[0x8efc6b4] main input debug: Buffering 81%
[0x8efc6b4] main input debug: creating aout
[0x8efc6b4] main input debug: Stream buffering done (477 ms in 0 ms)
[0xb45499c4] main audio output debug: looking for audio output module: 4 candidates
[0xb45499c4] alsa audio output debug: opening ALSA device `default'
[0xb45499c4] main audio output debug: using audio output module "alsa"
[0xb45499c4] main audio output debug: output 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0xb45499c4] main audio output debug: mixer 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0xb45499c4] main audio output debug: no need for any filter
[0x96f4e1c4] main generic debug: looking for audio mixer module: 6 candidates
[0x96f4e1c4] main generic debug: using audio mixer module "float32_mixer"
[0xb45499c4] main audio output debug: input 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0x96dc38bc] main audio filter debug: looking for audio filter module: 2 candidates
[0x96dc38bc] scaletempo audio filter debug: format: 44100 rate, 2 nch, 4 bps, fl32
[0x96dc38bc] scaletempo audio filter debug: params: 30 stride, 0.200 overlap, 14 search
[0x96dc38bc] scaletempo audio filter debug: 1.000 scale, 1323.000 stride_in, 1323 stride_out, 1059 standing, 264 overlap, 617 search, 2204 queue, fl32 mode
[0x96dc38bc] main audio filter debug: using audio filter module "scaletempo"
[0xb45499c4] main audio output debug: filter(s) 'f32l'->'f32l' 48510 Hz->44100 Hz Stereo->Stereo
[0x96dc3bec] main audio filter debug: looking for audio filter module: 22 candidates
[0x96dc3bec] main audio filter debug: using audio filter module "ugly_resampler"
[0xb45499c4] main audio output debug: found a filter for the whole conversion
[0x8ff740c] main decoder debug: End of audio preroll
[0x8efc6b4] main input debug: Decoder buffering done in 22 ms
[0xb45499c4] main audio output warning: PTS is out of range (-9982), dropping buffer
[0xb45499c4] main audio output warning: PTS is out of range (-23011), dropping buffer
Metadata ready, sending to zeitgeist 
stateChangedInternal newState: "PlayingState" previousState: "PlayingState" 
updateDuration Length changing from  -1  to  101328 
stateChangedInternal newState: "PlayingState" previousState: "PlayingState" 
[0x8efc6b4] main input debug: control type=0
[0x8efc6b4] main input debug: control: stopping input
[0x8ff740c] main decoder debug: removing module "vorbis"
[0x8ff740c] main decoder debug: killing decoder fourcc `vorb', 0 PES in FIFO
[0x96dc38bc] main audio filter debug: removing module "scaletempo"
[0x96dc3bec] main audio filter debug: removing module "ugly_resampler"
[0xb45499c4] main audio output debug: removing module "alsa"
[0x96f4e1c4] main generic debug: removing module "float32_mixer"
[0x8efc6b4] main input debug: releasing aout
[0x8efc6b4] main input debug: Program doesn't contain anymore ES
[0x8fccddc] main demux debug: removing module "ogg"
[0x93a5234] main stream debug: removing module "stream_filter_record"
[0x8edf9e4] main access debug: removing module "filesystem"
[0x8efc6b4] main input debug: thread ended
stateChangedInternal newState: "StoppedState" previousState: "PlayingState" 
stateChangedInternal newState: "StoppedState" previousState: "StoppedState" 
void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 5  QUrl( "" )  "" 
stateChangedInternal newState: "StoppedState" previousState: "StoppedState" 
setSource 
setSource Error: MediaSource is empty. 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
State changed from 2 to 1 -> sending to zeitgeist.

Comment 8 Myriam Schweingruber 2011-04-28 23:57:53 UTC

Thank you for the feedback.

Comment 9 Harald Sitter 2011-04-29 10:05:04 UTC

Please fetch a new log with the env vars *and* amarok started using amarok --debug.

Oh, and if at all possible, please use phonon vlc 0.4.0
http://apachelog.wordpress.com/2011/04/26/phonon-vlc-0-4-0/

The present log does not quite make sense, the url that fails is
"file:Musik/Mazzaferrata/Il primo libro delle Sonate a due
violini/./36 - Track36.ogg"
Which probably is missing a // after the file: part, so the question is who creates this bogus url and how does it arrive in Phonon vlc given that Phonon::MediaObject::setCurrentSource is apparently not called.

Comment 10 svenvermant 2011-04-29 11:19:03 UTC

Actually I cannot easily upgrade to phonon-vlc-0.4.0, it's not in the portage tree yet and I don't dare to install things manually here.

Concerning the debugging stuff, here we go:

amarok: BEGIN: void Playlist::PrettyListView::trackActivated(const QModelIndex&) 
amarok:   BEGIN: void Playlist::Actions::play(const QModelIndex&) 
amarok:     BEGIN: void Playlist::Actions::play(quint64, bool) 
amarok:       BEGIN: void EngineController::play(Meta::TrackPtr, uint) 
amarok:         BEGIN: void EngineController::stop(bool) 
void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 5  QUrl( "" )  "" 
setSource 
setSource Error: MediaSource is empty. 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
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:         END__: void EngineController::stop(bool) [Took: 0s] 
amarok:         [EngineController] play: bounded is  QObject(0x0)  current "Track35" 
amarok:         [EngineController] Just a normal, boring track... :-P 
amarok:         BEGIN: void EngineController::playUrl(const KUrl&, uint) 
amarok:           [EngineController] URL:  "file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./35%20-%20Track35.ogg" 
amarok:           [EngineController] offset:  0 
void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 0  QUrl( "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg" )  "" 
setSource 
setSource yeap, 'tis a local file or url "file" 
stateChangedInternal newState: "BufferingState" previousState: "StoppedState" 
loadMediaInternal "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg" 
stateChangedInternal newState: "StoppedState" previousState: "BufferingState" 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
amarok:           BEGIN: void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) 
amarok:             [EngineController] Using gain of 0 with relative peak of 0 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
amarok:             BEGIN: void Context::ContextView::slotTrackChanged(Meta::TrackPtr) 
amarok:             END__: void Context::ContextView::slotTrackChanged(Meta::TrackPtr) [Took: 0s] 
amarok:             BEGIN: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) 
amarok:             END__: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) [Took: 0s] 
amarok:             BEGIN: bool EngineController::isStream() 
amarok:             END__: bool EngineController::isStream() [Took: 0s] 
amarok:             [WikipediaEngine] Fetching langlinks: KUrl("http://en.wikipedia.org/w/api.php?action=query&prop=langlinks&titles=G.B.Mazzaferrata&format=xml&lllimit=100&redirects=1") 
amarok:             BEGIN: void TimecodeObserver::trackPlaying(Meta::TrackPtr) 
amarok:               current track name:  "Track35" 
amarok:               Track timecodeable 
amarok:             END__: void TimecodeObserver::trackPlaying(Meta::TrackPtr) [Took: 0s] 
amarok:             BEGIN: void Playlist::Actions::slotTrackPlaying(Meta::TrackPtr) 
amarok:               BEGIN: void StatusBar::updateTotalPlaylistLength() 
amarok:               END__: void StatusBar::updateTotalPlaylistLength() [Took: 0s] 
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:             END__: void Playlist::Actions::slotTrackPlaying(Meta::TrackPtr) [Took: 0s] 
amarok:             BEGIN: void ProgressWidget::trackLengthChanged(qint64) 
amarok:               new length:  28000 
amarok:               slider enabled! 
amarok:               BEGIN: void ProgressWidget::redrawBookmarks(const QString*) 
amarok:                 found  0  timecodes on this track 
amarok:               END__: void ProgressWidget::redrawBookmarks(const QString*) [Took: 0.05s] 
amarok:             END__: void ProgressWidget::trackLengthChanged(qint64) [Took: 0.05s] 
amarok:             BEGIN: void OSDWidget::show(const QString&, const QImage&) 
amarok:             END__: void OSDWidget::show(const QString&, const QImage&) [Took: 0s] 
amarok:             BEGIN: void CurrentEngine::trackPlaying(Meta::TrackPtr) 
amarok:               [CurrentEngine] updating track "Track35" 
amarok:             END__: void CurrentEngine::trackPlaying(Meta::TrackPtr) [Took: 0.013s] 
amarok:           END__: void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) [Took: 0.073s] 
play 
amarok:           BEGIN: void EngineController::slotMetaDataChanged() 
amarok:             [EngineController] Artist     :  ("") 
amarok:             [EngineController] Album      :  ("") 
amarok:             [EngineController] Title      :  ("35 - Track35.ogg") 
amarok:             [EngineController] Genre      :  ("") 
amarok:             [EngineController] Tracknumber:  ("") 
amarok:             [EngineController] Length     :  () 
amarok:             [EngineController] Track changed:  true current: 0x926f2d8 url "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg" 
amarok:             [EngineController] no spam 
amarok:           END__: void EngineController::slotMetaDataChanged() [Took: 0s] 
Metadata ready, sending to zeitgeist 
[0x93e7a5c] main input debug: Creating an input for '35 - Track35.ogg'
[0x93e7a5c] main input debug: thread (input) created at priority 10 (input/input.c:220)
stateChangedInternal newState: "PlayingState" previousState: "StoppedState" 
updateVolume Volume changed to -  29  From  29 
amarok:           [EngineController] track pos after play:  0 
amarok:         END__: void EngineController::playUrl(const KUrl&, uint) [Took: 0.076s] 
amarok:       END__: void EngineController::play(Meta::TrackPtr, uint) [Took: 0.076s] 
amarok:     END__: void Playlist::Actions::play(quint64, bool) [Took: 0.077s] 
amarok:   END__: void Playlist::Actions::play(const QModelIndex&) [Took: 0.077s] 
amarok: END__: void Playlist::PrettyListView::trackActivated(const QModelIndex&) [Took: 0.077s] 
State changed from 1 to 3 -> sending to zeitgeist. 
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State, Phonon::State) 
amarok: END__: void EngineController::slotStateChanged(Phonon::State, Phonon::State) [Took: 0s] 
State changed from 3 to 1 -> sending to zeitgeist. 
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State, Phonon::State) 
amarok: END__: void EngineController::slotStateChanged(Phonon::State, Phonon::State) [Took: 0s] 
[0x93a9634] main input debug: Creating an input for '35 - Track35.ogg'
[0x93e7a5c] main input debug: thread started
[0x93e7a5c] main input debug: using timeshift granularity of 50 MiB
[0x93e7a5c] main input debug: using timeshift path '/tmp'
[0x93e7a5c] main input debug: `file:///home/bjoern/Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/35%20-%20Track35.ogg' gives access `file' demux `' path `/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg'
[0x93e7a5c] main input debug: creating demux: access='file' demux='' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg'
[0x939db34] main demux debug: looking for access_demux module: 4 candidates
[0x831c934] main playlist debug: no fetch required for (null) (art currently (null))
amarok: BEGIN: void LyricsEngine::update() 
amarok:   BEGIN: void ScriptManager::notifyFetchLyrics(const QString&, const QString&) 
amarok:     SCRIPT "LyricWiki" :  "request URL: http://lyrics.wikia.com/api.php?action=query&prop=revisions&rvprop=content&format=xml&titles=G.B.Mazzaferrata:Track35" 
amarok:     BEGIN: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) 
amarok:     END__: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) [Took: 0s] 
amarok:   END__: void ScriptManager::notifyFetchLyrics(const QString&, const QString&) [Took: 0.039s] 
amarok: END__: void LyricsEngine::update() [Took: 0.039s] 
amarok: BEGIN: void ProgressWidget::redrawBookmarks(const QString*) 
amarok:   found  0  timecodes on this track 
amarok: END__: void ProgressWidget::redrawBookmarks(const QString*) [Took: 0s] 
[0x939db34] main demux debug: no access_demux module matching "file" could be loaded
[0x93e7a5c] main input debug: creating access 'file' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg'
[0x8dcb8f4] main access debug: looking for access module: 4 candidates
[0x8dcb8f4] filesystem access debug: opening file `/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg'
[0x8dcb8f4] main access debug: using access module "filesystem"
[0x96040dc] main stream debug: Using AStream*Stream
[0x96040dc] main stream debug: pre buffering
[0x96040dc] main stream debug: received first data after 0 ms
[0x96040dc] main stream debug: pre-buffering done 1024 bytes in 0s - 55555 KiB/s
[0x904aaec] main stream debug: looking for stream_filter module: 10 candidates
[0x904aaec] main stream debug: no stream_filter module matching "any" could be loaded
[0x9157d9c] main stream debug: looking for stream_filter module: 2 candidates
[0x9157d9c] main stream debug: using stream_filter module "stream_filter_record"
[0x93e7a5c] main input debug: creating demux: access='file' demux='' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg'
[0x904aaec] main demux debug: looking for demux module: 96 candidates
[0x904aaec] main demux debug: using demux module "ogg"
[0x93e7a5c] main input debug: looking for a subtitle file in /home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/
[0x93edd3c] main demux meta debug: looking for meta reader module: 0 candidates
[0x93edd3c] main demux meta debug: no meta reader module matched "any"
[0x93e7a5c] main input debug: `file:///home/bjoern/Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/35%20-%20Track35.ogg' successfully opened
[0x904aaec] ogg demux debug: found vorbis header
State changed from 1 to 2 -> sending to zeitgeist. 
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State, Phonon::State) 
amarok: END__: void EngineController::slotStateChanged(Phonon::State, Phonon::State) [Took: 0s] 
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok:   BEGIN: void CurrentTrack::resizeCover(const QPixmap&, qreal) 
[0x93e7a5c] main input debug: selecting program id=0
[0x939c2f4] main decoder debug: looking for decoder module: 52 candidates
[0x939c2f4] main decoder debug: using decoder module "vorbis"
[0x939c2f4] main decoder debug: thread (decoder) created at priority 5 (input/decoder.c:301)
[0x939c2f4] main decoder debug: thread started
[0x904aaec] ogg demux debug: beginning of a group of logical streams
[0x93e7a5c] main input debug: ES_OUT_RESET_PCR called
[0x939c2f4] main decoder debug: removing module "vorbis"
[0x939c2f4] main decoder debug: killing decoder fourcc `vorb', 0 PES in FIFO
[0x939c2f4] main decoder debug: looking for decoder module: 52 candidates
[0x939c2f4] main decoder debug: using decoder module "vorbis"
[0x939c2f4] main decoder debug: thread (decoder) created at priority 5 (input/decoder.c:301)
[0x939c2f4] main decoder debug: thread started
[0x939c2f4] vorbis decoder debug: channels:2 samplerate:44100 bitrate:192000
[0x93e7a5c] main input debug: Buffering 0%
[0x93e7a5c] main input debug: Buffering 52%
[0x93e7a5c] main input debug: Stream buffering done (390 ms in 0 ms)
[0x93e7a5c] main input debug: creating aout
[0x932d9d4] main audio output debug: looking for audio output module: 4 candidates
[0x932d9d4] alsa audio output debug: opening ALSA device `default'
[0x932d9d4] main audio output debug: using audio output module "alsa"
[0x932d9d4] main audio output debug: output 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0x932d9d4] main audio output debug: mixer 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0x932d9d4] main audio output debug: no need for any filter
[0x9355304] main generic debug: looking for audio mixer module: 6 candidates
[0x9355304] main generic debug: using audio mixer module "float32_mixer"
[0x932d9d4] main audio output debug: input 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0x9355dd4] main audio filter debug: looking for audio filter module: 2 candidates
[0x9355dd4] scaletempo audio filter debug: format: 44100 rate, 2 nch, 4 bps, fl32
[0x9355dd4] scaletempo audio filter debug: params: 30 stride, 0.200 overlap, 14 search
[0x9355dd4] scaletempo audio filter debug: 1.000 scale, 1323.000 stride_in, 1323 stride_out, 1059 standing, 264 overlap, 617 search, 2204 queue, fl32 mode
[0x9355dd4] main audio filter debug: using audio filter module "scaletempo"
[0x932d9d4] main audio output debug: filter(s) 'f32l'->'f32l' 48510 Hz->44100 Hz Stereo->Stereo
[0x935618c] main audio filter debug: looking for audio filter module: 22 candidates
[0x935618c] main audio filter debug: using audio filter module "ugly_resampler"
[0x932d9d4] main audio output debug: found a filter for the whole conversion
[0x939c2f4] main decoder debug: End of audio preroll
[0x93e7a5c] main input debug: Decoder buffering done in 229 ms
[0x932d9d4] main audio output warning: PTS is out of range (-9934), dropping buffer
[0x932d9d4] main audio output warning: PTS is out of range (-22969), dropping buffer
amarok:   END__: void CurrentTrack::resizeCover(const QPixmap&, qreal) [Took: 0.52s] 
amarok:   BEGIN: virtual bool MetaFile::Track::isEditable() const 
amarok:     "Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/./35 - Track35.ogg"  editable:  true 
amarok:   END__: virtual bool MetaFile::Track::isEditable() const [Took: 0s] 
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0.53s] 
amarok: BEGIN: void ProgressWidget::redrawBookmarks(const QString*) 
amarok:   found  0  timecodes on this track 
amarok: END__: void ProgressWidget::redrawBookmarks(const QString*) [Took: 0s] 
amarok: BEGIN: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
amarok: BEGIN: void EngineController::slotMetaDataChanged() 
amarok:   [EngineController] Artist     :  ("G.B.Mazzaferrata") 
amarok:   [EngineController] Album      :  ("Il primo libro delle Sonate a due violini, op.5 (1674)") 
amarok:   [EngineController] Title      :  ("Track35") 
amarok:   [EngineController] Genre      :  ("") 
amarok:   [EngineController] Tracknumber:  ("35") 
amarok:   [EngineController] Length     :  () 
amarok:   [EngineController] Track changed:  false current: 0x926f2d8 url "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/35 - Track35.ogg" 
amarok:   [EngineController] no spam 
amarok: END__: void EngineController::slotMetaDataChanged() [Took: 0s] 
Metadata ready, sending to zeitgeist 
stateChangedInternal newState: "PlayingState" previousState: "PlayingState" 
updateDuration Length changing from  -1  to  26841 
amarok: BEGIN: void EngineController::slotTrackLengthChanged(qint64) 
amarok:   BEGIN: void ProgressWidget::trackLengthChanged(qint64) 
amarok:     new length:  28000 
amarok:     slider enabled! 
amarok:     BEGIN: void ProgressWidget::redrawBookmarks(const QString*) 
amarok:       found  0  timecodes on this track 
amarok:     END__: void ProgressWidget::redrawBookmarks(const QString*) [Took: 0.002s] 
amarok:   END__: void ProgressWidget::trackLengthChanged(qint64) [Took: 0.002s] 
amarok: END__: void EngineController::slotTrackLengthChanged(qint64) [Took: 0.002s] 
amarok: [WikipediaEngine] Fetching listing: KUrl("http://en.wikipedia.org/w/api.php?action=query&list=search&srsearch=G.B.Mazzaferrata&srprop=size&srredirects=1&srlimit=20&format=xml") 
amarok: BEGIN: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) 
amarok: END__: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) [Took: 0s] 
amarok: BEGIN: void WikipediaEnginePrivate::_dataContainerUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void WikipediaEnginePrivate::_dataContainerUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
amarok: BEGIN: void WikipediaApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void WikipediaApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
amarok: BEGIN: void AmarokScript::AmarokLyricsScript::showLyricsNotFound(const QString&) const 
amarok:   BEGIN: void LyricsManager::lyricsNotFound(const QString&) 
amarok:     BEGIN: bool LyricsManager::showCached() 
amarok:     END__: bool LyricsManager::showCached() [Took: 0s] 
amarok:     BEGIN: void LyricsSubject::sendLyricsMessage(const QString&, const QString&) 
amarok:       BEGIN: virtual void LyricsEngine::lyricsMessage(const QString&, const QString&) 
amarok:       END__: virtual void LyricsEngine::lyricsMessage(const QString&, const QString&) [Took: 0s] 
amarok:     END__: void LyricsSubject::sendLyricsMessage(const QString&, const QString&) [Took: 0s] 
amarok:   END__: void LyricsManager::lyricsNotFound(const QString&) [Took: 0s] 
amarok: END__: void AmarokScript::AmarokLyricsScript::showLyricsNotFound(const QString&) const [Took: 0.001s] 
amarok: BEGIN: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
amarok: BEGIN: void SqlRegistry::emptyCache() 
amarok:   [SqlRegistry] Cache unchanged 
amarok: END__: void SqlRegistry::emptyCache() [Took: 0s] 
amarok: BEGIN: void ScanManager::checkForDirectoryChanges() 
amarok:   BEGIN: void DirWatchJob::setPaused(bool) 
amarok:   END__: void DirWatchJob::setPaused(bool) [Took: 0s] 
amarok: END__: void ScanManager::checkForDirectoryChanges() [Took: 0s] 
stateChangedInternal newState: "PlayingState" previousState: "PlayingState" 
void Phonon::MediaObjectPrivate::_k_aboutToFinish() 
amarok: BEGIN: void EngineController::slotAboutToFinish() 
amarok:   [EngineController] Track finished completely, updating statistics 
amarok:   BEGIN: void Statistics::StatisticsProvider::played(double, Meta::TrackPtr) 
amarok:     called with playedFraction =  1 
amarok:   END__: void Statistics::StatisticsProvider::played(double, Meta::TrackPtr) [Took: 0.001s] 
amarok:   BEGIN: void Playlist::Actions::requestNextTrack() 
amarok:     [Playlist::Actions] so far so good! 
amarok:     BEGIN: void Playlist::Actions::play(quint64, bool) 
amarok:       BEGIN: void EngineController::setNextTrack(Meta::TrackPtr) 
amarok:         [EngineController] locking mutex 
amarok:         [EngineController] locked! 
amarok:       END__: void EngineController::setNextTrack(Meta::TrackPtr) [Took: 0s] 
amarok:     END__: void Playlist::Actions::play(quint64, bool) [Took: 0s] 
amarok:   END__: void Playlist::Actions::requestNextTrack() [Took: 0s] 
amarok: END__: void EngineController::slotAboutToFinish() [Took: 0.001s] 
setNextSource 
[0x904aaec] ogg demux debug: end of a group of logical streams
[0x904aaec] ogg demux warning: couldn't find any ogg logical stream
[0x93e7a5c] main input debug: EOF reached
setSource 
setSource yeap, 'tis a local file or url "file" 
stateChangedInternal newState: "BufferingState" previousState: "PlayingState" 
stateChangedInternal no-op gapless item awaiting in queue -  1 
loadMediaInternal "file:Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/./36 - Track36.ogg" 
stateChangedInternal newState: "StoppedState" previousState: "PlayingState" 
stateChangedInternal no-op gapless item awaiting in queue -  1 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
amarok: BEGIN: void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) 
amarok:   [EngineController] Using gain of 0 with relative peak of 0 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
amarok:   BEGIN: void Context::ContextView::slotTrackChanged(Meta::TrackPtr) 
amarok:   END__: void Context::ContextView::slotTrackChanged(Meta::TrackPtr) [Took: 0s] 
[0x939c2f4] main decoder debug: removing module "vorbis"
[0x939c2f4] main decoder debug: killing decoder fourcc `vorb', 0 PES in FIFO
[0x9355dd4] main audio filter debug: removing module "scaletempo"
[0x935618c] main audio filter debug: removing module "ugly_resampler"
[0x932d9d4] main audio output debug: removing module "alsa"
[0x9355304] main generic debug: removing module "float32_mixer"
[0x93e7a5c] main input debug: releasing aout
[0x93e7a5c] main input debug: Program doesn't contain anymore ES
[0x904aaec] main demux debug: removing module "ogg"
[0x9157d9c] main stream debug: removing module "stream_filter_record"
[0x8dcb8f4] main access debug: removing module "filesystem"
[0x93e7a5c] main input debug: thread ended
amarok:   BEGIN: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) 
amarok:   END__: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) [Took: 0s] 
amarok:   BEGIN: void TimecodeObserver::trackPlaying(Meta::TrackPtr) 
amarok:     current track name:  "Track36" 
amarok:     Track timecodeable 
amarok:   END__: void TimecodeObserver::trackPlaying(Meta::TrackPtr) [Took: 0s] 
amarok:   BEGIN: void Playlist::Actions::slotTrackPlaying(Meta::TrackPtr) 
amarok:     BEGIN: void StatusBar::updateTotalPlaylistLength() 
amarok:     END__: void StatusBar::updateTotalPlaylistLength() [Took: 0s] 
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:   END__: void Playlist::Actions::slotTrackPlaying(Meta::TrackPtr) [Took: 0.001s] 
amarok:   BEGIN: void ProgressWidget::trackLengthChanged(qint64) 
amarok:     new length:  33000 
amarok:     slider enabled! 
amarok:     BEGIN: void ProgressWidget::redrawBookmarks(const QString*) 
amarok:       found  0  timecodes on this track 
amarok:     END__: void ProgressWidget::redrawBookmarks(const QString*) [Took: 0s] 
amarok:   END__: void ProgressWidget::trackLengthChanged(qint64) [Took: 0s] 
amarok:   BEGIN: void OSDWidget::show(const QString&, const QImage&) 
amarok:   END__: void OSDWidget::show(const QString&, const QImage&) [Took: 0s] 
amarok:   BEGIN: void CurrentEngine::trackPlaying(Meta::TrackPtr) 
amarok:     [CurrentEngine] updating track "Track36" 
amarok:   END__: void CurrentEngine::trackPlaying(Meta::TrackPtr) [Took: 0s] 
amarok: END__: void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) [Took: 0.097s] 
play 
amarok: BEGIN: void EngineController::slotMetaDataChanged() 
amarok:   [EngineController] Artist     :  ("") 
amarok:   [EngineController] Album      :  ("") 
amarok:   [EngineController] Title      :  ("36 - Track36.ogg") 
amarok:   [EngineController] Genre      :  ("") 
amarok:   [EngineController] Tracknumber:  ("") 
amarok:   [EngineController] Length     :  () 
amarok:   [EngineController] Track changed:  true current: 0x926d9d8 url "file:Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/./36 - Track36.ogg" 
amarok:   [EngineController] no spam 
amarok: END__: void EngineController::slotMetaDataChanged() [Took: 0s] 
Metadata ready, sending to zeitgeist 
[0x8dc9e8c] main input debug: Creating an input for '36 - Track36.ogg'
[0x8dc9e8c] main input debug: thread (input) created at priority 10 (input/input.c:220)
stateChangedInternal newState: "PlayingState" previousState: "PlayingState" 
updateVolume Volume changed to -  29  From  29 
[0x94fc874] main input debug: Creating an input for '36 - Track36.ogg'
[0x831c934] main playlist debug: no fetch required for (null) (art currently (null))
[0x8dc9e8c] main input debug: thread started
[0x8dc9e8c] main input debug: using timeshift granularity of 50 MiB
[0x8dc9e8c] main input debug: using timeshift path '/tmp'
[0x8dc9e8c] main input debug: `file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg' gives access `' demux `' path `file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg'
[0x8dc9e8c] main input debug: creating demux: access='' demux='' path='file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg'
[0x9163fac] main demux debug: looking for access_demux module: 12 candidates
libdvdnav: Using dvdnav version 4.1.3
amarok: BEGIN: void LyricsEngine::update() 
amarok:   BEGIN: void ScriptManager::notifyFetchLyrics(const QString&, const QString&) 
amarok:     SCRIPT "LyricWiki" :  "request URL: http://lyrics.wikia.com/api.php?action=query&prop=revisions&rvprop=content&format=xml&titles=G.B.Mazzaferrata:Track36" 
amarok:     BEGIN: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) 
amarok:     END__: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) [Took: 0s] 
amarok:   END__: void ScriptManager::notifyFetchLyrics(const QString&, const QString&) [Took: 0.006s] 
amarok: END__: void LyricsEngine::update() [Took: 0.017s] 
libdvdread: Using libdvdcss version 1.2.10 for DVD access
libdvdread: Could not open file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg with libdvdcss.
libdvdread: Can't open file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg for reading
libdvdnav: vm: failed to open/read the DVD
[0x9163fac] dvdnav demux warning: cannot open DVD (file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg)
libdvdnav: Using dvdnav version 4.1.3
libdvdread: Using libdvdcss version 1.2.10 for DVD access
libdvdread: Could not open file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg with libdvdcss.
libdvdread: Can't open file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg for reading
libdvdnav: vm: failed to open/read the DVD
[0x9163fac] dvdnav demux warning: cannot open DVD (file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg)
[0x9163fac] main demux debug: no access_demux module matching "any" could be loaded
[0x8dc9e8c] main input debug: creating access '' path='file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg'
[0xb448b2dc] main access debug: looking for access module: 6 candidates
[0xb448b2dc] filesystem access debug: opening file `file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg'
[0xb448b2dc] filesystem access error: cannot open file file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg (No such file or directory)                                                                                                                                 
[0xb448b2dc] main access error: Einlesen der Datei fehlgeschlagen
[0xb448b2dc] main access error: VLC konnte die Datei "file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg" nicht lesen.                                                                                                                                                
[0xb448b2dc] filesystem access debug: opening file `file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg'
[0xb448b2dc] filesystem access error: cannot open file file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg (No such file or directory)                                                                                                                                 
[0xb448b2dc] main access error: Einlesen der Datei fehlgeschlagen
[0xb448b2dc] main access error: VLC konnte die Datei "file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg" nicht lesen.                                                                                                                                                
[0xb448b2dc] main access debug: no access module matching "any" could be loaded
[0x8dc9e8c] main input error: open of `file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg' failed: (null)
[0x8dc9e8c] main input error: Ihre Eingabe konnte nicht geöffnet werden
[0x8dc9e8c] main input error: VLC kann die MRL 'file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./36%20-%20Track36.ogg' nicht öffnen. Sehen Sie für Details im Fehlerprotokoll nach.                                                                                                      
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok:   BEGIN: virtual bool MetaFile::Track::isEditable() const 
amarok:     "Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/./36 - Track36.ogg"  editable:  true 
amarok:   END__: virtual bool MetaFile::Track::isEditable() const [Took: 0s] 
[0x8dc9e8c] main input debug: thread ended
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0.17s] 
amarok: BEGIN: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
amarok: BEGIN: void EngineController::slotFinished() 
amarok:   BEGIN: void TimecodeObserver::stopped(qint64, qint64) 
amarok:   END__: void TimecodeObserver::stopped(qint64, qint64) [Took: 0s] 
amarok:   BEGIN: void OSDWidget::show(const QString&, const QImage&) 
amarok:   END__: void OSDWidget::show(const QString&, const QImage&) [Took: 0.02s] 
amarok:   BEGIN: void WikipediaEnginePrivate::_stopped() 
amarok:   END__: void WikipediaEnginePrivate::_stopped() [Took: 0s] 
amarok:   BEGIN: void Context::ContextView::slotTrackChanged(Meta::TrackPtr) 
amarok:   END__: void Context::ContextView::slotTrackChanged(Meta::TrackPtr) [Took: 0s] 
amarok:   BEGIN: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) 
amarok:   END__: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) [Took: 0s] 
void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 5  QUrl( "" )  "" 
stateChangedInternal newState: "StoppedState" previousState: "PlayingState" 
stateChangedInternal newState: "StoppedState" previousState: "StoppedState" 
setSource 
setSource Error: MediaSource is empty. 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
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: END__: void EngineController::slotFinished() [Took: 0.18s] 
stateChangedInternal newState: "ErrorState" previousState: "StoppedState" 
amarok: BEGIN: void ProgressWidget::redrawBookmarks(const QString*) 
amarok: END__: void ProgressWidget::redrawBookmarks(const QString*) [Took: 0s] 
amarok: BEGIN: void LyricsEngine::update() 
amarok:   [LyricsEngine] no current track 
amarok: END__: void LyricsEngine::update() [Took: 0s] 
State changed from 2 to 1 -> sending to zeitgeist. 
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State, Phonon::State) 
amarok: END__: void EngineController::slotStateChanged(Phonon::State, Phonon::State) [Took: 0.003s] 
State changed from 1 to 5 -> sending to zeitgeist. 
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State, Phonon::State) 
amarok:   [WARNING] [EngineController] Phonon failed to play this URL. Error:  "No active input" 
amarok:   [WARNING] [EngineController] Forcing phonon engine reinitialization. 
amarok:   BEGIN: void EngineController::initializePhonon() 
"PVLC(2): Object: Phonon::VLC::VLCMediaObject" 
"PVLC(2): Object: Phonon::VLC::AudioOutput" 
"PVLC(2): Object: Phonon::VLC::VLCMediaObject" 
"PVLC(2): Object: Phonon::VLC::AudioOutput" 
emitting a state change because the backend object has been replaced 
"PVLC(2): Object: Phonon::VLC::VLCMediaObject" 
"PVLC(2): Object: Phonon::VLC::AudioOutput" 
"PVLC(2): Backend connected Phonon::VLC::VLCMediaObject to Phonon::VLC::AudioOutput" 
"PVLC(2): Object: Phonon::VLC::VLCMediaObject" 
"PVLC(2): Object: Phonon::VLC::AudioOutput" 
void Phonon::FrontendInterfacePrivate::_backendObjectChanged() 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
amarok:     [EngineController] Tick Interval (actual):  100 
amarok:   END__: void EngineController::initializePhonon() [Took: 0.026s] 
amarok:   BEGIN: void EngineController::slotAboutToFinish() 
amarok:     [EngineController] Track finished completely, updating statistics 
amarok:     BEGIN: void Playlist::Actions::requestNextTrack() 
amarok:       [Playlist::Actions] so far so good! 
amarok:       BEGIN: void Playlist::Actions::play(quint64, bool) 
amarok:         BEGIN: void EngineController::setNextTrack(Meta::TrackPtr) 
amarok:           [EngineController] locking mutex 
amarok:           [EngineController] locked! 
amarok:           BEGIN: void EngineController::play(Meta::TrackPtr, uint) 
amarok:             BEGIN: void EngineController::stop(bool) 
void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 5  QUrl( "" )  "" 
setSource 
setSource Error: MediaSource is empty. 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
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:             END__: void EngineController::stop(bool) [Took: 0s] 
amarok:             [EngineController] play: bounded is  QObject(0x0)  current "Track37" 
amarok:             [EngineController] Just a normal, boring track... :-P 
amarok:             BEGIN: void EngineController::playUrl(const KUrl&, uint) 
amarok:               [EngineController] URL:  "file:Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/./37%20-%20Track37.ogg" 
amarok:               [EngineController] offset:  0 
void Phonon::MediaObject::setCurrentSource(const Phonon::MediaSource&) 0  QUrl( "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg" )  "" 
setSource 
setSource yeap, 'tis a local file or url "file" 
stateChangedInternal newState: "BufferingState" previousState: "StoppedState" 
loadMediaInternal "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg" 
stateChangedInternal newState: "StoppedState" previousState: "BufferingState" 
void Phonon::MediaObjectPrivate::_k_currentSourceChanged(const Phonon::MediaSource&) 
amarok:               BEGIN: void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) 
amarok:                 [EngineController] Using gain of 0 with relative peak of 0 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
"PVLC(2): createObject() : VolumeFaderEffect not implemented" 
amarok:                 BEGIN: void Context::ContextView::slotTrackChanged(Meta::TrackPtr) 
amarok:                 END__: void Context::ContextView::slotTrackChanged(Meta::TrackPtr) [Took: 0s] 
amarok:                 BEGIN: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) 
amarok:                 END__: void LyricsAppletPrivate::_trackDataChanged(Meta::TrackPtr) [Took: 0s] 
amarok:                 BEGIN: bool EngineController::isStream() 
amarok:                 END__: bool EngineController::isStream() [Took: 0s] 
amarok:                 [WikipediaEngine] Fetching langlinks: KUrl("http://en.wikipedia.org/w/api.php?action=query&prop=langlinks&titles=G.B.Mazzaferrata&format=xml&lllimit=100&redirects=1") 
amarok:                 BEGIN: void TimecodeObserver::trackPlaying(Meta::TrackPtr) 
amarok:                   current track name:  "Track37" 
amarok:                   Track timecodeable 
amarok:                 END__: void TimecodeObserver::trackPlaying(Meta::TrackPtr) [Took: 0s] 
amarok:                 BEGIN: void Playlist::Actions::slotTrackPlaying(Meta::TrackPtr) 
amarok:                   BEGIN: void StatusBar::updateTotalPlaylistLength() 
amarok:                   END__: void StatusBar::updateTotalPlaylistLength() [Took: 0s] 
amarok:                   BEGIN: void Playlist::PrettyListView::slotPlaylistActiveTrackChanged() 
amarok:                     BEGIN: void Playlist::PrettyListView::scrollToActiveTrack() 
amarok:                     END__: void Playlist::PrettyListView::scrollToActiveTrack() [Took: 0.002s] 
amarok:                   END__: void Playlist::PrettyListView::slotPlaylistActiveTrackChanged() [Took: 0.002s] 
amarok:                 END__: void Playlist::Actions::slotTrackPlaying(Meta::TrackPtr) [Took: 0.003s] 
amarok:                 BEGIN: void ProgressWidget::trackLengthChanged(qint64) 
amarok:                   new length:  96000 
amarok:                   slider enabled! 
amarok:                   BEGIN: void ProgressWidget::redrawBookmarks(const QString*) 
amarok:                     found  0  timecodes on this track 
amarok:                   END__: void ProgressWidget::redrawBookmarks(const QString*) [Took: 0.002s] 
amarok:                 END__: void ProgressWidget::trackLengthChanged(qint64) [Took: 0.002s] 
amarok:                 BEGIN: void OSDWidget::show(const QString&, const QImage&) 
amarok:                 END__: void OSDWidget::show(const QString&, const QImage&) [Took: 0s] 
amarok:                 BEGIN: void CurrentEngine::trackPlaying(Meta::TrackPtr) 
amarok:                   [CurrentEngine] updating track "Track37" 
amarok:                 END__: void CurrentEngine::trackPlaying(Meta::TrackPtr) [Took: 0s] 
amarok:               END__: void EngineController::slotNewTrackPlaying(const Phonon::MediaSource&) [Took: 0.034s] 
play 
amarok:               BEGIN: void EngineController::slotMetaDataChanged() 
amarok:                 [EngineController] Artist     :  ("") 
amarok:                 [EngineController] Album      :  ("") 
amarok:                 [EngineController] Title      :  ("37 - Track37.ogg") 
amarok:                 [EngineController] Genre      :  ("") 
amarok:                 [EngineController] Tracknumber:  ("") 
amarok:                 [EngineController] Length     :  () 
amarok:                 [EngineController] Track changed:  true current: 0x9274030 url "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg" 
amarok:                 [EngineController] no spam 
amarok:               END__: void EngineController::slotMetaDataChanged() [Took: 0s] 
Metadata ready, sending to zeitgeist 
[0x8dc9e8c] main input debug: Creating an input for '37 - Track37.ogg'
[0x8dc9e8c] main input debug: thread (input) created at priority 10 (input/input.c:220)
stateChangedInternal newState: "PlayingState" previousState: "StoppedState" 
updateVolume Volume changed to -  50  From  29 
amarok:               [EngineController] track pos after play:  0 
amarok:             END__: void EngineController::playUrl(const KUrl&, uint) [Took: 0.038s] 
amarok:           END__: void EngineController::play(Meta::TrackPtr, uint) [Took: 0.038s] 
amarok:         END__: void EngineController::setNextTrack(Meta::TrackPtr) [Took: 0.038s] 
amarok:       END__: void Playlist::Actions::play(quint64, bool) [Took: 0.038s] 
amarok:     END__: void Playlist::Actions::requestNextTrack() [Took: 0.038s] 
amarok:   END__: void EngineController::slotAboutToFinish() [Took: 0.038s] 
amarok: END__: void EngineController::slotStateChanged(Phonon::State, Phonon::State) [Took: 0.065s] 
[0x8dc9e8c] main input debug: thread started
[0x8dc9e8c] main input debug: using timeshift granularity of 50 MiB
[0x8dc9e8c] main input debug: using timeshift path '/tmp'
[0x8dc9e8c] main input debug: `file:///home/bjoern/Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/37%20-%20Track37.ogg' gives access `file' demux `' path `/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg'
[0x8dc9e8c] main input debug: creating demux: access='file' demux='' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg'
[0x8dc8b5c] main demux debug: looking for access_demux module: 4 candidates
amarok: BEGIN: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok:   BEGIN: virtual bool MetaFile::Track::isEditable() const 
amarok:     "Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/./37 - Track37.ogg"  editable:  true 
amarok:   END__: virtual bool MetaFile::Track::isEditable() const [Took: 0s] 
[0x8d8ef44] main input debug: Creating an input for '37 - Track37.ogg'
[0x831c934] main playlist debug: no fetch required for (null) (art currently (null))
amarok: END__: void CurrentTrack::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0.018s] 
amarok: BEGIN: void WikipediaEnginePrivate::_dataContainerUpdated(const QString&, const QHash<QString, QVariant>&) 
[0x8dc8b5c] main demux debug: no access_demux module matching "file" could be loaded
[0x8dc9e8c] main input debug: creating access 'file' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg'
amarok: END__: void WikipediaEnginePrivate::_dataContainerUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0.005s] 
amarok: BEGIN: void WikipediaApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok:   [WikipediaApplet] stopped 
amarok: END__: void WikipediaApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
[0x8d24834] main access debug: looking for access module: 4 candidates
[0x8d24834] filesystem access debug: opening file `/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg'
[0x8d24834] main access debug: using access module "filesystem"
[0x93e7bc4] main stream debug: Using AStream*Stream
[0x93e7bc4] main stream debug: pre buffering
[0x93e7bc4] main stream debug: received first data after 0 ms
[0x93e7bc4] main stream debug: pre-buffering done 1024 bytes in 0s - 55555 KiB/s
[0x82eeed4] main stream debug: looking for stream_filter module: 10 candidates
[0x82eeed4] main stream debug: no stream_filter module matching "any" could be loaded
[0x92d042c] main stream debug: looking for stream_filter module: 2 candidates
[0x92d042c] main stream debug: using stream_filter module "stream_filter_record"
[0x8dc9e8c] main input debug: creating demux: access='file' demux='' path='/home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg'
[0x8dc8b5c] main demux debug: looking for demux module: 96 candidates
[0x8dc8b5c] main demux debug: using demux module "ogg"
[0x8dc9e8c] main input debug: looking for a subtitle file in /home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/
amarok: BEGIN: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
[0x9604d44] main demux meta debug: looking for meta reader module: 0 candidates
[0x9604d44] main demux meta debug: no meta reader module matched "any"
amarok: END__: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
[0x8dc9e8c] main input debug: `file:///home/bjoern/Musik/Mazzaferrata/Il%20primo%20libro%20delle%20Sonate%20a%20due%20violini/37%20-%20Track37.ogg' successfully opened
[0x8dc8b5c] ogg demux debug: found vorbis header
[0x8dc9e8c] main input debug: selecting program id=0
[0x82ecb04] main decoder debug: looking for decoder module: 52 candidates
[0x82ecb04] main decoder debug: using decoder module "vorbis"
[0x82ecb04] main decoder debug: thread (decoder) created at priority 5 (input/decoder.c:301)
[0x82ecb04] main decoder debug: thread started
[0x8dc8b5c] ogg demux debug: beginning of a group of logical streams
[0x8dc9e8c] main input debug: ES_OUT_RESET_PCR called
[0x82ecb04] main decoder debug: removing module "vorbis"
[0x82ecb04] main decoder debug: killing decoder fourcc `vorb', 0 PES in FIFO
[0x82ecb04] main decoder debug: looking for decoder module: 52 candidates
[0x82ecb04] main decoder debug: using decoder module "vorbis"
amarok: BEGIN: void ProgressWidget::redrawBookmarks(const QString*) 
[0x82ecb04] main decoder debug: thread (decoder) created at priority 5 (input/decoder.c:301)
amarok:   found  0  timecodes on this track 
amarok: END__: void ProgressWidget::redrawBookmarks(const QString*) [Took: 0.054s] 
State changed from 1 to 3 -> sending to zeitgeist. 
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State, Phonon::State) 
amarok: END__: void EngineController::slotStateChanged(Phonon::State, Phonon::State) [Took: 0s] 
State changed from 3 to 1 -> sending to zeitgeist. 
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State, Phonon::State) 
amarok: END__: void EngineController::slotStateChanged(Phonon::State, Phonon::State) [Took: 0s] 
amarok: BEGIN: void LyricsEngine::update() 
amarok:   BEGIN: void ScriptManager::notifyFetchLyrics(const QString&, const QString&) 
amarok:     SCRIPT "LyricWiki" :  "request URL: http://lyrics.wikia.com/api.php?action=query&prop=revisions&rvprop=content&format=xml&titles=G.B.Mazzaferrata:Track37" 
amarok:     BEGIN: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) 
[0x82ecb04] main decoder debug: thread started
[0x82ecb04] vorbis decoder debug: channels:2 samplerate:44100 bitrate:192000
amarok:     END__: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) [Took: 0.001s] 
amarok:   END__: void ScriptManager::notifyFetchLyrics(const QString&, const QString&) [Took: 0.005s] 
amarok: END__: void LyricsEngine::update() [Took: 0.005s] 
State changed from 1 to 2 -> sending to zeitgeist. 
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State, Phonon::State) 
amarok: END__: void EngineController::slotStateChanged(Phonon::State, Phonon::State) [Took: 0.001s] 
[0x8dc9e8c] main input debug: Buffering 0%
[0x8dc9e8c] main input debug: Buffering 81%
[0x8dc9e8c] main input debug: Stream buffering done (477 ms in 0 ms)
[0x8dc9e8c] main input debug: creating aout
[0x9dabdf4] main audio output debug: looking for audio output module: 4 candidates
[0x9dabdf4] alsa audio output debug: opening ALSA device `default'
[0x9dabdf4] main audio output debug: using audio output module "alsa"
[0x9dabdf4] main audio output debug: output 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0x9dabdf4] main audio output debug: mixer 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0x9dabdf4] main audio output debug: no need for any filter
[0xb442dfec] main generic debug: looking for audio mixer module: 6 candidates
[0xb442dfec] main generic debug: using audio mixer module "float32_mixer"
[0x9dabdf4] main audio output debug: input 'f32l' 44100 Hz Stereo frame=1 samples/8 bytes
[0xb445a064] main audio filter debug: looking for audio filter module: 2 candidates
[0xb445a064] scaletempo audio filter debug: format: 44100 rate, 2 nch, 4 bps, fl32
[0xb445a064] scaletempo audio filter debug: params: 30 stride, 0.200 overlap, 14 search
[0xb445a064] scaletempo audio filter debug: 1.000 scale, 1323.000 stride_in, 1323 stride_out, 1059 standing, 264 overlap, 617 search, 2204 queue, fl32 mode
[0xb445a064] main audio filter debug: using audio filter module "scaletempo"
[0x9dabdf4] main audio output debug: filter(s) 'f32l'->'f32l' 48510 Hz->44100 Hz Stereo->Stereo
[0xb445d634] main audio filter debug: looking for audio filter module: 22 candidates
[0xb445d634] main audio filter debug: using audio filter module "ugly_resampler"
[0x9dabdf4] main audio output debug: found a filter for the whole conversion
[0x82ecb04] main decoder debug: End of audio preroll
[0x8dc9e8c] main input debug: Decoder buffering done in 32 ms
[0x9dabdf4] main audio output warning: PTS is out of range (-9972), dropping buffer
[0x9dabdf4] main audio output warning: PTS is out of range (-23013), dropping buffer
amarok: BEGIN: void EngineController::slotMetaDataChanged() 
amarok:   [EngineController] Artist     :  ("G.B.Mazzaferrata") 
amarok:   [EngineController] Album      :  ("Il primo libro delle Sonate a due violini, op.5 (1674)") 
amarok:   [EngineController] Title      :  ("Track37") 
amarok:   [EngineController] Genre      :  ("") 
amarok:   [EngineController] Tracknumber:  ("37") 
amarok:   [EngineController] Length     :  () 
amarok:   [EngineController] Track changed:  false current: 0x9274030 url "file:///home/bjoern/Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/37 - Track37.ogg" 
amarok:   [EngineController] no spam 
amarok: END__: void EngineController::slotMetaDataChanged() [Took: 0s] 
Metadata ready, sending to zeitgeist 
stateChangedInternal newState: "PlayingState" previousState: "PlayingState" 
updateDuration Length changing from  -1  to  101328 
amarok: BEGIN: void EngineController::slotTrackLengthChanged(qint64) 
amarok:   BEGIN: void ProgressWidget::trackLengthChanged(qint64) 
amarok:     new length:  96000 
amarok:     slider enabled! 
amarok:     BEGIN: void ProgressWidget::redrawBookmarks(const QString*) 
amarok:       found  0  timecodes on this track 
amarok:     END__: void ProgressWidget::redrawBookmarks(const QString*) [Took: 0s] 
amarok:   END__: void ProgressWidget::trackLengthChanged(qint64) [Took: 0s] 
amarok: END__: void EngineController::slotTrackLengthChanged(qint64) [Took: 0s] 
amarok: BEGIN: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
amarok: BEGIN: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) 
amarok: END__: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) [Took: 0s] 
amarok: [WikipediaEngine] Fetching listing: KUrl("http://en.wikipedia.org/w/api.php?action=query&list=search&srsearch=G.B.Mazzaferrata&srprop=size&srredirects=1&srlimit=20&format=xml") 
amarok: BEGIN: void AmarokScript::AmarokLyricsScript::showLyricsNotFound(const QString&) const 
amarok:   BEGIN: void LyricsManager::lyricsNotFound(const QString&) 
amarok:     BEGIN: bool LyricsManager::showCached() 
amarok:     END__: bool LyricsManager::showCached() [Took: 0s] 
amarok:     BEGIN: void LyricsSubject::sendLyricsMessage(const QString&, const QString&) 
amarok:       BEGIN: virtual void LyricsEngine::lyricsMessage(const QString&, const QString&) 
amarok:       END__: virtual void LyricsEngine::lyricsMessage(const QString&, const QString&) [Took: 0s] 
amarok:     END__: void LyricsSubject::sendLyricsMessage(const QString&, const QString&) [Took: 0s] 
amarok:   END__: void LyricsManager::lyricsNotFound(const QString&) [Took: 0s] 
amarok: END__: void AmarokScript::AmarokLyricsScript::showLyricsNotFound(const QString&) const [Took: 0s] 
amarok: BEGIN: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
amarok: BEGIN: void WikipediaEnginePrivate::_dataContainerUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void WikipediaEnginePrivate::_dataContainerUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
amarok: BEGIN: void WikipediaApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void WikipediaApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
amarok: BEGIN: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) 
amarok: END__: static QScriptValue Downloader::init(QScriptContext*, QScriptEngine*, bool) [Took: 0s] 
amarok: BEGIN: void AmarokScript::AmarokLyricsScript::showLyricsNotFound(const QString&) const 
amarok:   BEGIN: void LyricsManager::lyricsNotFound(const QString&) 
amarok:     BEGIN: bool LyricsManager::showCached() 
amarok:     END__: bool LyricsManager::showCached() [Took: 0s] 
amarok:     BEGIN: void LyricsSubject::sendLyricsMessage(const QString&, const QString&) 
amarok:       BEGIN: virtual void LyricsEngine::lyricsMessage(const QString&, const QString&) 
amarok:       END__: virtual void LyricsEngine::lyricsMessage(const QString&, const QString&) [Took: 0s] 
amarok:     END__: void LyricsSubject::sendLyricsMessage(const QString&, const QString&) [Took: 0s] 
amarok:   END__: void LyricsManager::lyricsNotFound(const QString&) [Took: 0s] 
amarok: END__: void AmarokScript::AmarokLyricsScript::showLyricsNotFound(const QString&) const [Took: 0s] 
amarok: BEGIN: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) 
amarok: END__: void LyricsApplet::dataUpdated(const QString&, const QHash<QString, QVariant>&) [Took: 0s] 
amarok: BEGIN: void SqlRegistry::emptyCache() 
amarok:   [SqlRegistry] Cache unchanged 
amarok: END__: void SqlRegistry::emptyCache() [Took: 0s] 
stateChangedInternal newState: "PlayingState" previousState: "PlayingState" 
amarok: BEGIN: void EngineController::playPause() 
amarok:   [EngineController] PlayPause: EngineController state 2 
stateChangedInternal newState: "PausedState" previousState: "PlayingState" 
[0x8dc9e8c] main input debug: control type=1
amarok:   BEGIN: void OSDWidget::show(const QString&, const QImage&) 
amarok:   END__: void OSDWidget::show(const QString&, const QImage&) [Took: 0.004s] 
amarok: END__: void EngineController::playPause() [Took: 0.045s] 
State changed from 2 to 4 -> sending to zeitgeist. 
amarok: BEGIN: void EngineController::slotStateChanged(Phonon::State, Phonon::State) 
amarok: END__: void EngineController::slotStateChanged(Phonon::State, Phonon::State) [Took: 0s] 
stateChangedInternal newState: "PausedState" previousState: "PausedState" 
[0x9dabdf4] alsa audio output debug: recovered from buffer underrun
amarok: BEGIN: void SqlRegistry::emptyCache() 
amarok:   [SqlRegistry] Cache unchanged 
amarok: END__: void SqlRegistry::emptyCache() [Took: 0s] 
amarok: BEGIN: void ScanManager::checkForDirectoryChanges() 
amarok:   BEGIN: void DirWatchJob::setPaused(bool) 
amarok:   END__: void DirWatchJob::setPaused(bool) [Took: 0s] 
amarok: END__: void ScanManager::checkForDirectoryChanges() [Took: 0s] 
amarok: BEGIN: void SqlRegistry::emptyCache() 
amarok:   [SqlRegistry] Cache unchanged 
amarok: END__: void SqlRegistry::emptyCache() [Took: 0s] 
amarok: BEGIN: void SqlRegistry::emptyCache() 
amarok:   [SqlRegistry] Cache unchanged 
amarok: END__: void SqlRegistry::emptyCache() [Took: 0s] 
amarok: BEGIN: void ScanManager::checkForDirectoryChanges() 
amarok:   BEGIN: void DirWatchJob::setPaused(bool) 
amarok:   END__: void DirWatchJob::setPaused(bool) [Took: 0s] 
amarok: END__: void ScanManager::checkForDirectoryChanges() [Took: 0s]

Comment 11 Myriam Schweingruber 2011-05-01 14:04:13 UTC

Thank you for the information.

Comment 12 Harald Sitter 2011-07-26 11:26:07 UTC

Please attach the m3u file.

Also any chance of getting a 0.4 log yet?

Looking at the latest log I can savely say that it fails because of the invalid URI (file: instead of file://) which seems to be caused by setNextSource (or rather the transition from current to next source).

I do however believe that this is long fixed by 0.4 and its use of Phonon::Mrl.

So, unless the m3u is invalid this ought to be working just fine with 0.4

Comment 13 svenvermant 2011-07-26 12:26:42 UTC

Created attachment 62205 [details]
log for phonon-vlc-0.4.0

Here is the m3u list:

#EXTM3U
#EXTINF:83,Track01
./01 - Track01.ogg
#EXTINF:71,Track02
./02 - Track02.ogg
#EXTINF:38,Track03
./03 - Track03.ogg
#EXTINF:37,Track04
./04 - Track04.ogg
#EXTINF:71,Track05
./05 - Track05.ogg
#EXTINF:104,Track06
./06 - Track06.ogg
#EXTINF:73,Track07
./07 - Track07.ogg
#EXTINF:47,Track08
./08 - Track08.ogg
#EXTINF:56,Track09
./09 - Track09.ogg
#EXTINF:92,Track10
./10 - Track10.ogg
#EXTINF:66,Track11
./11 - Track11.ogg
#EXTINF:88,Track12
./12 - Track12.ogg
#EXTINF:118,Track13
./13 - Track13.ogg
#EXTINF:44,Track14
./14 - Track14.ogg
#EXTINF:84,Track15
./15 - Track15.ogg
#EXTINF:59,Track16
./16 - Track16.ogg
#EXTINF:48,Track17
./17 - Track17.ogg
#EXTINF:73,Track18
./18 - Track18.ogg
#EXTINF:103,Track19
./19 - Track19.ogg
#EXTINF:38,Track20
./20 - Track20.ogg
#EXTINF:83,Track21
./21 - Track21.ogg
#EXTINF:27,Track22
./22 - Track22.ogg
#EXTINF:85,Track23
./23 - Track23.ogg
#EXTINF:74,Track24
./24 - Track24.ogg
#EXTINF:196,Track25
./25 - Track25.ogg
#EXTINF:104,Track26
./26 - Track26.ogg
#EXTINF:50,Track27
./27 - Track27.ogg
#EXTINF:37,Track28
./28 - Track28.ogg
#EXTINF:63,Track29
./29 - Track29.ogg
#EXTINF:123,Track30
./30 - Track30.ogg
#EXTINF:33,Track31
./31 - Track31.ogg
#EXTINF:30,Track32
./32 - Track32.ogg
#EXTINF:161,Track33
./33 - Track33.ogg
#EXTINF:88,Track34
./34 - Track34.ogg
#EXTINF:28,Track35
./35 - Track35.ogg
#EXTINF:33,Track36
./36 - Track36.ogg
#EXTINF:96,Track37
./37 - Track37.ogg
#EXTINF:34,Track38
./38 - Track38.ogg
#EXTINF:91,Track39
./39 - Track39.ogg
#EXTINF:38,Track40
./40 - Track40.ogg
#EXTINF:68,Track41
./41 - Track41.ogg
#EXTINF:56,Track42
./42 - Track42.ogg
#EXTINF:60,Track43
./43 - Track43.ogg
#EXTINF:79,Track44
./44 - Track44.ogg
#EXTINF:63,Track45
./45 - Track45.ogg
#EXTINF:49,Track46
./46 - Track46.ogg
#EXTINF:23,Track47
./47 - Track47.ogg
#EXTINF:42,Track48
./48 - Track48.ogg
#EXTINF:27,Track49
./49 - Track49.ogg

I attached the log for phonon-vlc-0.4.0 as it is too long to be included here.

Comment 14 Andreas K. Huettel 2011-11-08 19:51:36 UTC

Ping- the requested information is above... HASINFO now :)

Comment 15 Myriam Schweingruber 2011-11-08 20:20:40 UTC

Seen that, yes, but since then another backend-vlc version was released, does this still apply?

Comment 16 svenvermant 2011-11-08 21:47:25 UTC

The problem persists with phonon-vlc-0.4.1.

Comment 17 Myriam Schweingruber 2011-11-09 00:18:59 UTC

Thank you for the fast feedback.

Comment 18 Harald Sitter 2012-01-23 19:05:27 UTC

I do strongly believe that this is a bug in Amarok.

in the 0.4 log we can see

PHONON-VLC BEGIN: virtual void Phonon::VLC::MediaObject::setNextSource(const Phonon::MediaSource&) 
PHONON-VLC    QUrl( "file:Musik/Mazzaferrata/Il primo libro delle Sonate a due violini/./47 - Track47.ogg" )  
PHONON-VLC END__: virtual void Phonon::VLC::MediaObject::setNextSource(const Phonon::MediaSource&) [Took: 0s] 

now setNextSource gets its MediaSource from the phonon mediasource queue, however one can only add stuff to said queue by building a mediasource, therefore I must assume Amarok is building a mediasource with a bogus url... which would also explain why so many backends are affected.

Comment 19 svenvermant 2012-01-23 19:12:00 UTC

Well, whatever it was, with gentoo's amarok-2.5.0-r1 and the phonon-gstreamer the problem is gone :-) I'm so happy!!!

Comment 20 Myriam Schweingruber 2012-01-24 18:23:14 UTC

Thank you for the feedback.