Page 1 of 1

Album played counts is counting with double speed.

PostPosted: Mon Aug 24, 2009 3:35 pm
by kdid
On my Subsonic the album number of played songs is counting two per played song. Do others see the same?

So if I play an album with 9 tracks once, then the counter increases with 18 instead of 9.

Is it a bug in Subsonic, or is there something that can provoke this to happen that i can turn off?

PostPosted: Mon Aug 24, 2009 7:53 pm
by jigsaw
Hi kdid

I have never experienced this myself. Are you using the web-player or an external player? Does it happen on both?

When you play a song, do you see multiple instances of the log-message "INFO PlaylistInputStream Opening new song ...."?

-jigsaw

PostPosted: Mon Aug 24, 2009 10:16 pm
by kdid
Hmmm. Looking at this now I see that the double counting only happens when songs is transcoded. In the log below I changed the limit from 112 to 160 midway and the double logging did not happen anymore.

[25.08.09 00:03:46 CEST] INFO StreamController Starting stream kjell@192.168.10.1:4326 (Opera/9.64 (Windows NT 5.1; U; nb) Presto/2.1.1)
[25.08.09 00:03:46 CEST] INFO PlaylistInputStream Opening new song Forever You and I\01 Forever You and I.mp3
[25.08.09 00:03:46 CEST] DEBUG TranscodeInputStream Starting transcoder: [c:\subsonic\transcode\lame] [-S] [-h] [-b] [112] [x:\Musikk\MP3\Ernesto Cortazar II\Forever You and I\01 Forever You and I.mp3] [-]
[25.08.09 00:03:46 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) ID3v2 found. Be aware that the ID3 tag is currently lost when transcoding.
[25.08.09 00:03:46 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) LAME version 3.96.1 (http://lame.sourceforge.net/)
[25.08.09 00:03:46 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) CPU features: MMX (ASM used), 3DNow! (ASM used), SSE, SSE2
[25.08.09 00:03:46 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) Using polyphase lowpass filter, transition band: 15826 Hz - 16360 Hz
[25.08.09 00:03:46 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) Encoding x:\Musikk\MP3\Ernesto Cortazar II\Forever You and I\01 Forever You and I.mp3
[25.08.09 00:03:46 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) to
[25.08.09 00:03:46 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) Encoding as 44.1 kHz 112 kbps j-stereo MPEG-1 Layer III (12.6x) qval=2
[25.08.09 00:03:46 CEST] DEBUG AudioScrobblerService Successfully scrobbled song 'Forever You and I' for user Xxxxxxx at Last.fm.
[25.08.09 00:04:14 CEST] INFO StreamController Stopping stream kjell@192.168.10.1:4326 (Opera/9.64 (Windows NT 5.1; U; nb) Presto/2.1.1)
[25.08.09 00:04:14 CEST] INFO StreamController Starting stream kjell@192.168.10.1:4350 (Opera/9.64 (Windows NT 5.1; U; nb) Presto/2.1.1)
[25.08.09 00:04:14 CEST] INFO PlaylistInputStream Opening new song Forever You and I\01 Forever You and I.mp3
[25.08.09 00:04:14 CEST] DEBUG TranscodeInputStream Starting transcoder: [c:\subsonic\transcode\lame] [-S] [-h] [-b] [112] [x:\Musikk\MP3\Ernesto Cortazar II\Forever You and I\01 Forever You and I.mp3] [-]
[25.08.09 00:04:14 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) ID3v2 found. Be aware that the ID3 tag is currently lost when transcoding.
[25.08.09 00:04:14 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) LAME version 3.96.1 (http://lame.sourceforge.net/)
[25.08.09 00:04:14 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) CPU features: MMX (ASM used), 3DNow! (ASM used), SSE, SSE2
[25.08.09 00:04:14 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) Using polyphase lowpass filter, transition band: 15826 Hz - 16360 Hz
[25.08.09 00:04:14 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) Encoding x:\Musikk\MP3\Ernesto Cortazar II\Forever You and I\01 Forever You and I.mp3
[25.08.09 00:04:14 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) to
[25.08.09 00:04:14 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) Encoding as 44.1 kHz 112 kbps j-stereo MPEG-1 Layer III (12.6x) qval=2
[25.08.09 00:04:15 CEST] INFO StreamController Stopping stream kjell@192.168.10.1:4350 (Opera/9.64 (Windows NT 5.1; U; nb) Presto/2.1.1)
[25.08.09 00:08:05 CEST] INFO StreamController Starting stream kjell@192.168.10.1:4572 (Opera/9.64 (Windows NT 5.1; U; nb) Presto/2.1.1)
[25.08.09 00:08:05 CEST] INFO PlaylistInputStream Opening new song Forever You and I\03 Eternity.mp3
[25.08.09 00:08:08 CEST] DEBUG AudioScrobblerService Successfully scrobbled song 'Eternity' for user Xxxxxxx at Last.fm.
[25.08.09 00:08:30 CEST] INFO StreamController Stopping stream kjell@192.168.10.1:4572 (Opera/9.64 (Windows NT 5.1; U; nb) Presto/2.1.1)
[25.08.09 00:10:59 CEST] INFO StreamController Starting stream kjell@192.168.10.1:4772 (Opera/9.64 (Windows NT 5.1; U; nb) Presto/2.1.1)
[25.08.09 00:10:59 CEST] INFO PlaylistInputStream Opening new song Forever You and I\05 Alone.mp3
[25.08.09 00:10:59 CEST] DEBUG AudioScrobblerService Successfully scrobbled song 'Alone' for user Xxxxxxx at Last.fm.
[25.08.09 00:11:34 CEST] INFO StreamController Stopping stream kjell@192.168.10.1:4772 (Opera/9.64 (Windows NT 5.1; U; nb) Presto/2.1.1)

------------

The problem is that most of my music is in flac, so all those is double counted.

same issue here

PostPosted: Fri Oct 09, 2009 3:18 pm
by kermit22
good call on the transcoding/scrobbler issue. I was getting frustrated with the double submission whenever i listened at my work and not anywhere else. After reading your post I went in and checked my work player settings and it was set to max out 128kbps. Since all of my music is V0 quality all of my scrobbles on last.fm were duplicated. When I set it to no limit they went back to being single scrobbled. Thanks for posting your workaround. I hope that Sindre will have time to take a look at this issue.

PostPosted: Mon Oct 12, 2009 9:09 pm
by kdid
My problem is that most of my music is in flac, and I only have a 400 kbit/sec line out, so I have to rely on transcoding and enforce a usable low limit of 128kbit/sec to be able to stream at least 3 users at the same time. So for me it is not a solution to allow no limit transfers.

So, yeah, I hope Sindre will have time to do a fix for this bug. - One of my friends also have Subsonic installed and he feels this is a very annoying problem.

Personally I would had liked to see a fix for the cutting of play length of low bitrate songs that is transcoded over a fix for this bug.

PostPosted: Tue Oct 13, 2009 7:19 am
by sindre_mehus
I'll look into the double-scrobbling issue. Thanks.

PostPosted: Wed Oct 14, 2009 11:21 am
by kdid
Just to ensure that we talk about the same.

It is counting double both on LastFM and in the internal database counter.

Thanks for looking into this. Appreciated. :-)

PostPosted: Wed Oct 14, 2009 11:48 am
by sindre_mehus
By the way, if someone can show me a log from when the error occurs that would be great.

PostPosted: Thu Oct 15, 2009 1:45 pm
by kdid
My current log:

Strangley the song "Home" was only scrobbled once it looks like in the log. But the other two songs was scrobbled twice.

Looking at the log on Last.fm I find the same is logged there.

But the log indicated that all files was handled twice, so all of them probably was count twice internally.

----

I played the three files again by clicking on the first one in the playlist and let it play again and this time it did scrobble all three songs twice. I do not know why it did skip one the first time.

Looking at the log it looks like the scrobbling isn't happening at the same time every time compared to when the stream is stopped as logged in the log. Sometimes the scrobbling happens before the stream is stopped, Sometimes after.

Here is the log for the first play of the mention files:

[15.10.09 15:00:12 CEST] INFO PlaylistInputStream Opening new song 1997 - White Stones\12 - Celebration.mp3
[15.10.09 15:00:12 CEST] DEBUG TranscodeInputStream Starting transcoder: [c:\subsonic\transcode\lame] [--quiet] [-h] [-b] [160] [x:\Musikk\MP3\Secret Garden\1997 - White Stones\12 - Celebration.mp3] [-]
[15.10.09 15:00:12 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) ID3v2 found. Be aware that the ID3 tag is currently lost when transcoding.
[15.10.09 15:00:14 CEST] DEBUG AudioScrobblerService Successfully scrobbled song 'Celebration' for user XXXX at Last.fm.
[15.10.09 15:00:45 CEST] INFO StreamController Stopping stream kjell@192.168.10.1:4803 (Opera/9.80 (Windows NT 5.1; U; nb) Presto/2.2.15 Version/10.00)
[15.10.09 15:00:45 CEST] INFO StreamController Starting stream kjell@192.168.10.1:4838 (Opera/9.80 (Windows NT 5.1; U; nb) Presto/2.2.15 Version/10.00)
[15.10.09 15:00:45 CEST] INFO PlaylistInputStream Opening new song 1997 - White Stones\12 - Celebration.mp3
[15.10.09 15:00:45 CEST] DEBUG TranscodeInputStream Starting transcoder: [c:\subsonic\transcode\lame] [--quiet] [-h] [-b] [160] [x:\Musikk\MP3\Secret Garden\1997 - White Stones\12 - Celebration.mp3] [-]
[15.10.09 15:00:45 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) ID3v2 found. Be aware that the ID3 tag is currently lost when transcoding.
[15.10.09 15:00:46 CEST] INFO StreamController Stopping stream kjell@192.168.10.1:4838 (Opera/9.80 (Windows NT 5.1; U; nb) Presto/2.2.15 Version/10.00)
[15.10.09 15:00:47 CEST] DEBUG AudioScrobblerService Successfully scrobbled song 'Celebration' for user XXXX at Last.fm.
[15.10.09 15:04:07 CEST] INFO StreamController Starting stream kjell@192.168.10.1:1072 (Opera/9.80 (Windows NT 5.1; U; nb) Presto/2.2.15 Version/10.00)
[15.10.09 15:04:07 CEST] INFO PlaylistInputStream Opening new song 1997 - White Stones\13 - Home.mp3
[15.10.09 15:04:07 CEST] DEBUG TranscodeInputStream Starting transcoder: [c:\subsonic\transcode\lame] [--quiet] [-h] [-b] [160] [x:\Musikk\MP3\Secret Garden\1997 - White Stones\13 - Home.mp3] [-]
[15.10.09 15:04:07 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) ID3v2 found. Be aware that the ID3 tag is currently lost when transcoding.
[15.10.09 15:04:08 CEST] DEBUG AudioScrobblerService Successfully scrobbled song 'Home' for user XXXX at Last.fm.
[15.10.09 15:04:36 CEST] INFO StreamController Stopping stream kjell@192.168.10.1:1072 (Opera/9.80 (Windows NT 5.1; U; nb) Presto/2.2.15 Version/10.00)
[15.10.09 15:04:36 CEST] INFO StreamController Starting stream kjell@192.168.10.1:1109 (Opera/9.80 (Windows NT 5.1; U; nb) Presto/2.2.15 Version/10.00)
[15.10.09 15:04:36 CEST] INFO PlaylistInputStream Opening new song 1997 - White Stones\13 - Home.mp3
[15.10.09 15:04:36 CEST] DEBUG TranscodeInputStream Starting transcoder: [c:\subsonic\transcode\lame] [--quiet] [-h] [-b] [160] [x:\Musikk\MP3\Secret Garden\1997 - White Stones\13 - Home.mp3] [-]
[15.10.09 15:04:36 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) ID3v2 found. Be aware that the ID3 tag is currently lost when transcoding.
[15.10.09 15:04:36 CEST] INFO StreamController Stopping stream kjell@192.168.10.1:1109 (Opera/9.80 (Windows NT 5.1; U; nb) Presto/2.2.15 Version/10.00)
[15.10.09 15:07:29 CEST] INFO StreamController Starting stream kjell@192.168.10.1:1289 (Opera/9.80 (Windows NT 5.1; U; nb) Presto/2.2.15 Version/10.00)
[15.10.09 15:07:29 CEST] INFO PlaylistInputStream Opening new song 1997 - White Stones\14 - Illumination.mp3
[15.10.09 15:07:29 CEST] DEBUG TranscodeInputStream Starting transcoder: [c:\subsonic\transcode\lame] [--quiet] [-h] [-b] [160] [x:\Musikk\MP3\Secret Garden\1997 - White Stones\14 - Illumination.mp3] [-]
[15.10.09 15:07:29 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) ID3v2 found. Be aware that the ID3 tag is currently lost when transcoding.
[15.10.09 15:07:30 CEST] DEBUG AudioScrobblerService Successfully scrobbled song 'Illumination' for user XXXX at Last.fm.
[15.10.09 15:08:14 CEST] INFO StreamController Stopping stream kjell@192.168.10.1:1289 (Opera/9.80 (Windows NT 5.1; U; nb) Presto/2.2.15 Version/10.00)
[15.10.09 15:08:14 CEST] INFO StreamController Starting stream kjell@192.168.10.1:1326 (Opera/9.80 (Windows NT 5.1; U; nb) Presto/2.2.15 Version/10.00)
[15.10.09 15:08:14 CEST] INFO PlaylistInputStream Opening new song 1997 - White Stones\14 - Illumination.mp3
[15.10.09 15:08:14 CEST] DEBUG TranscodeInputStream Starting transcoder: [c:\subsonic\transcode\lame] [--quiet] [-h] [-b] [160] [x:\Musikk\MP3\Secret Garden\1997 - White Stones\14 - Illumination.mp3] [-]
[15.10.09 15:08:14 CEST] DEBUG InputStreamReaderThread (c:\subsonic\transcode\lame) ID3v2 found. Be aware that the ID3 tag is currently lost when transcoding.
[15.10.09 15:08:14 CEST] INFO StreamController Stopping stream kjell@192.168.10.1:1326 (Opera/9.80 (Windows NT 5.1; U; nb) Presto/2.2.15 Version/10.00)
[15.10.09 15:08:15 CEST] DEBUG AudioScrobblerService Successfully scrobbled song 'Illumination' for user XXXX at Last.fm.