Stutter/skips in Android client

[Pishtim]

This problem is getting to be too much to bear at this point. I would really hate to have to uninstall this program from my HTC Evo, it has such great potential if this could be solved.

If any one has found a solution, please reply with your solution, or possible fixes.

BTW, this problem only occurs when there are songs downloading in the background, not necessarily the current song. Does not matter if I'm using 3g, or a fast WiFi connection. I'm no programmer, but it seems as though the music is not getting enough priority. I see that this has been solved by transcoding, but all my songs are already mp3's. Should I try to transcode to another format?

[seanpkeown]

At first i thought that it was a transcoding problem but i got nowhere trying to encode the songs as slower bit-rate or as sending them as a different format.

Last night i decided to watch the logs on my phone and here is what i got. Ignore the word puke as it is the song title but look at the part STARTED -> COMPLETED and then look right below Restarting player from position for some reason it shows the song downloading correctly then out of the blue to restarts the player from another position. There is probably a reason for this but i don't know.


If you notice at the bottom the song is completely downloaded and yet it still skips.
Look below
09-26 16:41:42.443 9822 10115 I Util : Copied /sdcard/subsonic/music/Eminem/Encore Disc/07-Puke.mp3.128.partial to /sdcard/subsonic/music/Eminem/Encore Disc/07-Puke.complete.mp3

Code: Select all

09-26 16:40:24.163    91   111 I ActivityManager: Displayed activity net.sourceforge.subsonic.androidapp/.activity.DownloadActivity: 744 ms
09-26 16:40:24.423  9822 10116 I DownloadServiceImpl: Buffering /sdcard/subsonic/music/Eminem/Encore Disc/07-Puke.mp3.128.partial (0)
09-26 16:40:25.425  9822 10116 I DownloadServiceImpl: Buffering /sdcard/subsonic/music/Eminem/Encore Disc/07-Puke.mp3.128.partial (32768)
09-26 16:40:26.433  9822 10116 I DownloadServiceImpl: Buffering /sdcard/subsonic/music/Eminem/Encore Disc/07-Puke.mp3.128.partial (87135)
09-26 16:40:27.443  9822 10116 I DownloadServiceImpl: DOWNLOADING -> IDLE
09-26 16:40:27.983  9822 10116 I DownloadServiceImpl: IDLE -> PREPARING
09-26 16:40:28.023  9822 10116 I DownloadServiceImpl: PREPARING -> PREPARED
09-26 16:40:28.033  9822 10116 I DownloadServiceImpl: PREPARED -> STARTED
09-26 16:40:28.163  9822 10115 I DownloadFile: Downloaded 176 KB of Puke
09-26 16:40:28.313  8126  8128 W AudioFlinger: write blocked for 191 msecs
09-26 16:40:31.163  9822 10115 I DownloadFile: Downloaded 344 KB of Puke
09-26 16:40:34.175  9822 10115 I DownloadFile: Downloaded 500 KB of Puke
09-26 16:40:37.215  9822 10115 I DownloadFile: Downloaded 651 KB of Puke
09-26 16:40:39.243  9822  9822 I DownloadServiceImpl: STARTED -> COMPLETED
09-26 16:40:39.293  9822  9822 I DownloadServiceImpl: COMPLETED -> IDLE
09-26 16:40:39.303  9822 10124 I DownloadServiceImpl: IDLE -> DOWNLOADING
09-26 16:40:39.313  9822 10124 I DownloadServiceImpl: DOWNLOADING -> IDLE
09-26 16:40:39.343  9822 10124 I DownloadServiceImpl: IDLE -> PREPARING
09-26 16:40:39.443  9822 10124 I DownloadServiceImpl: PREPARING -> PREPARED
09-26 16:40:39.453  9822 10124 I DownloadServiceImpl: Restarting player from position 10915
09-26 16:40:39.553  9822 10124 I DownloadServiceImpl: PREPARED -> STARTED
09-26 16:40:40.253  9822 10115 I DownloadFile: Downloaded 808 KB of Puke
09-26 16:40:43.333  9822 10115 I DownloadFile: Downloaded 967 KB of Puke
09-26 16:40:46.455  9822 10115 I DownloadFile: Downloaded 1.11 MB of Puke
09-26 16:40:49.763  9822 10115 I DownloadFile: Downloaded 1.26 MB of Puke
09-26 16:40:52.813  9822 10115 I DownloadFile: Downloaded 1.41 MB of Puke
09-26 16:40:55.953  9822 10115 I DownloadFile: Downloaded 1.56 MB of Puke
09-26 16:40:59.073  9822 10115 I DownloadFile: Downloaded 1.73 MB of Puke
09-26 16:41:02.085  9822 10115 I DownloadFile: Downloaded 1.88 MB of Puke
09-26 16:41:05.094  9822 10115 I DownloadFile: Downloaded 2.04 MB of Puke
09-26 16:41:08.123  9822 10115 I DownloadFile: Downloaded 2.19 MB of Puke
09-26 16:41:11.203  9822 10115 I DownloadFile: Downloaded 2.34 MB of Puke
09-26 16:41:14.203  9822 10115 I DownloadFile: Downloaded 2.51 MB of Puke
09-26 16:41:17.215  9822 10115 I DownloadFile: Downloaded 2.66 MB of Puke
09-26 16:41:18.123  9822  9822 I DownloadServiceImpl: STARTED -> COMPLETED
09-26 16:41:18.163  9822  9822 I DownloadServiceImpl: COMPLETED -> IDLE
09-26 16:41:18.173  9822 10128 I DownloadServiceImpl: IDLE -> DOWNLOADING
09-26 16:41:18.183  9822 10128 I DownloadServiceImpl: DOWNLOADING -> IDLE
09-26 16:41:18.213  9822 10128 I DownloadServiceImpl: IDLE -> PREPARING
09-26 16:41:18.333  9822 10128 I DownloadServiceImpl: PREPARING -> PREPARED
09-26 16:41:18.343  9822 10128 I DownloadServiceImpl: Restarting player from position 49407
09-26 16:41:18.393  9822 10128 I DownloadServiceImpl: PREPARED -> STARTED
09-26 16:41:20.243  9822 10115 I DownloadFile: Downloaded 2.80 MB of Puke
09-26 16:41:23.313  9822 10115 I DownloadFile: Downloaded 2.95 MB of Puke
09-26 16:41:26.343  9822 10115 I DownloadFile: Downloaded 3.08 MB of Puke
09-26 16:41:29.453  9822 10115 I DownloadFile: Downloaded 3.24 MB of Puke
09-26 16:41:32.525  9822 10115 I DownloadFile: Downloaded 3.39 MB of Puke
09-26 16:41:35.523  9822 10115 I DownloadFile: Downloaded 3.55 MB of Puke
09-26 16:41:38.563  9822 10115 I DownloadFile: Downloaded 3.72 MB of Puke
09-26 16:41:39.883  9822 10115 I DownloadFile: Downloaded 3965596 bytes to /sdcard/subsonic/music/Eminem/Encore Disc/07-Puke.mp3.128.partial
09-26 16:41:42.443  9822 10115 I Util    : Copied /sdcard/subsonic/music/Eminem/Encore Disc/07-Puke.mp3.128.partial to /sdcard/subsonic/music/Eminem/Encore Disc/07-Puke.complete.mp3
09-26 16:43:26.943  9822  9822 I DownloadServiceImpl: STARTED -> COMPLETED
09-26 16:43:26.993  9822  9822 I DownloadServiceImpl: COMPLETED -> IDLE
09-26 16:43:27.003  9822 10132 I DownloadServiceImpl: IDLE -> DOWNLOADING
09-26 16:43:27.013  9822 10132 I DownloadServiceImpl: DOWNLOADING -> IDLE
09-26 16:43:27.033  9822 10132 I DownloadServiceImpl: IDLE -> PREPARING
09-26 16:43:27.163  9822 10132 I DownloadServiceImpl: PREPARING -> PREPARED
09-26 16:43:27.163  9822 10132 I DownloadServiceImpl: Restarting player from position 177858
09-26 16:43:27.223  9822 10132 I DownloadServiceImpl: PREPARED -> STARTED
09-26 16:44:37.263  9822  9822 I DownloadServiceImpl: STARTED -> COMPLETED
09-26 16:44:37.313  9822  9822 I DownloadServiceImpl: COMPLETED -> IDLE
09-26 16:44:59.583   146   146 E EONS    : EF_PNN: No short Name
09-26 16:45:01.213   143   412 I TLSStateManager: org.apache.harmony.nio.internal.SocketChannelImpl@4350ee38: Read 1309 bytes into buffer
09-26 16:45:01.473   143   590 I PacketReader: Processing a message
09-26 16:45:01.573   143   590 I StatusDataListener: Received Status.DATA message
09-26 16:45:01.683   143   590 I StatusSignalAdapter: Preparing to broadcast Status intent with 3 statuses
09-26 16:45:01.843   143   590 I StatusSignalAdapter: Finished broadcasting Status intent
09-26 16:45:02.133   143   590 I StatusDataListener: Finished processing Status.DATA message

My phone version is below.

Android Version 1.5
Motorola Backflip

[sn0skier]

Yeah this is a problem for me too. I'm not sure if it is only when a song is downloading, but I know that it happens even when the song currently playing is not downloading. People should send e-mails to the dev with links to this page. The skipping is driving me nuts.

[sigel]

I agree, it sucks!

It seems to always skip in the beginning around the same time, every song.

Do any devs ever read this forum ever? I see 95% of questions unanswered.

[Pishtim]

*bump*

[sn0skier]

So I've actually noticed that this happens to a lesser extant on the HTC music player, that when it happens the phone is really laggy in general, and that it happens more often with 4g turned on on my evo, so a few questions.

1. Does anyone have this problem and NOT have HTC sense?

2. Has anyone else had this happen with stock or HTC music player?

3. Does it happen for people more often with 3g, 4g, or Wi-Fi on?

4. When you encounter this problem, is the phone lagging in general?

[technics2000]

This is what's coming up in my logs everytime it skips

Code: Select all

10-04 15:41:14.411  2993  3361 I DownloadFile: Downloaded 12.77 MB of Hyph Mngo
10-04 15:41:16.371  1160  3422 D OMX_MP3 : MP3DEC_HandleUSNError():3543 IUALG_WARN_PLAYCOMPLETED!
10-04 15:41:16.371  1160  3420 E ProfileVideoFrameDrops: PVMediaOutputNodePort :: Early 0 frames :: OnTime 0 frames :: Late 0 frames :: Total 2163 frames
10-04 15:41:16.371  1160  3420 E ProfileVideoFrameDrops: PVMediaOutputNodePort :: Early 0.000000 % :: OnTime 0.000000 % :: Late -0.000000 %
10-04 15:41:16.645  1160  1259 D AudioHardwareMot: AudioStreamOutMot::setParameters() fm_attenuate=0;fm_mute=0
10-04 15:41:16.699  2993  2993 I DownloadServiceImpl: STARTED -> COMPLETED
10-04 15:41:16.699  2993  2993 D CancellableTask: Cancelling net.sourceforge.subsonic.androidapp.service.DownloadServiceImpl$BufferTask@4649b880
10-04 15:41:16.707  1160  3420 D         : enter SharedLibraryLookup
10-04 15:41:16.707  1160  3420 D         : enter GetFactoryAndMimeString
10-04 15:41:16.715  1160  3422 D OMX_MP3 : MP3DEC_LCML_Callback():2580 stop ack. received. stop waiting for sending disable command completed
10-04 15:41:16.785  1160  3420 D TIOMX_CORE: Found matching pHandle(0x2eb88) at index 5 with refCount 1
10-04 15:41:16.793  2993  2993 I DownloadServiceImpl: COMPLETED -> IDLE
10-04 15:41:16.801  2993  3424 D CancellableTask: Starting thread for net.sourceforge.subsonic.androidapp.service.DownloadServiceImpl$BufferTask@463cfae0
10-04 15:41:16.801  2993  3424 I DownloadServiceImpl: IDLE -> DOWNLOADING
10-04 15:41:16.801  2993  3424 I DownloadServiceImpl: DOWNLOADING -> IDLE
10-04 15:41:16.817  1160  3425 D         : enter PVGetInterface
10-04 15:41:16.817  1160  3425 D         : enter Instance
10-04 15:41:16.817  1160  3425 D         : enter SharedLibraryLookup
10-04 15:41:16.817  1160  3425 D         : enter RegisterAllRecognizers
10-04 15:41:16.840  1160  3420 D         : enter UnregisterAllRecognizers
10-04 15:41:16.840  2993  3424 I DownloadServiceImpl: IDLE -> PREPARING
10-04 15:41:16.848  1160  3425 D         : enter PVOMA1MOTRecognizerPlugin::Recognize
10-04 15:41:16.848  1160  3425 D         : PVOMA1MOTRecognizerPlugin:Recognize MOT_SVC_drm_openSession failed and session =-4
10-04 15:41:16.856  1160  3425 D         : enter PVGetInterface
10-04 15:41:16.856  1160  3425 D         : enter Instance
10-04 15:41:16.856  1160  3425 D         : enter SharedLibraryLookup
10-04 15:41:16.856  1160  3425 D         : enter GetFactoryAndMimeString
10-04 15:41:16.856  1160  3425 E         : This file is not ASF file.
10-04 15:41:16.856  1160  3425 D         : PVMFCPMMotPlugInOMA1:SetSourceInitializationData in

10-04 15:41:16.856  1160  3425 D         : sourceURL is /mnt/sdcard/subsonic/music/null/21-Hyph Mngo.mp3.0.partial
10-04 15:41:16.864  1160  3425 D         : PVMFCPMMotPlugInOMA1:SetSourceInitializationData MOT_SVC_drm_openSession not oma drm file
10-04 15:41:16.871  1160  3425 D TIOMX_CORE: Found component OMX.TI.MP3.decode with refCount 0
10-04 15:41:16.871  1160  3425 D OMX_MP3 : OMX_ComponentInit():216 Entering OMX_ComponentInit
10-04 15:41:16.879  2993  2997 W MediaPlayer: info/warning (1, 44)
10-04 15:41:16.879  2993  2993 I MediaPlayer: Info (1,44)
10-04 15:41:16.879  2993  3424 I DownloadServiceImpl: PREPARING -> PREPARED
10-04 15:41:16.879  2993  3424 I DownloadServiceImpl: Restarting player from position 268664
10-04 15:41:16.895  1160  3426 D OMX_MP3 : MP3DEC_HandleCommand():1697 Flushing input port
10-04 15:41:16.903  1160  3427 D OMX_MP3 : MP3DEC_LCML_Callback():2707 flush ack. received. for input port
10-04 15:41:16.903  1160  3426 D OMX_MP3 : MP3DEC_HandleCommand():1755 Flushing output port
10-04 15:41:16.903  1160  3427 D OMX_MP3 : MP3DEC_LCML_Callback():2750 flush ack. received. for output port
10-04 15:41:16.903  2993  3424 I DownloadServiceImpl: PREPARED -> STARTED
10-04 15:41:16.903  2993  3424 D CancellableTask: Stopping thread for net.sourceforge.subsonic.androidapp.service.DownloadServiceImpl$BufferTask@463cfae0
10-04 15:41:16.903  2993  2998 W MediaPlayer: info/warning (1, 44)
10-04 15:41:16.910  2993  2993 I MediaPlayer: Info (1,44)
10-04 15:41:17.418  2993  3361 I DownloadFile: Downloaded 12.90 MB of Hyph Mngo

[technics2000]

I checked errors in ddms and it looks like these entries might be the problem

Code: Select all

10-04 15:37:37.520: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0 frames :: OnTime 0 frames :: Late 0 frames :: Total 615 frames
10-04 15:37:37.520: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0.000000 % :: OnTime 0.000000 % :: Late -0.000000 %
10-04 15:37:37.903: ERROR/(1160): This file is not ASF file.
10-04 15:37:58.044: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0 frames :: OnTime 0 frames :: Late 0 frames :: Total 781 frames
10-04 15:37:58.044: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0.000000 % :: OnTime 180132.500000 % :: Late -0.000000 %
10-04 15:37:58.559: ERROR/(1160): This file is not ASF file.
10-04 15:38:23.590: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0 frames :: OnTime 0 frames :: Late 0 frames :: Total 963 frames
10-04 15:38:23.590: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0.000000 % :: OnTime 90066.250000 % :: Late -0.000000 %
10-04 15:38:24.043: ERROR/(1160): This file is not ASF file.
10-04 15:38:54.285: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0 frames :: OnTime 0 frames :: Late 0 frames :: Total 1165 frames
10-04 15:38:54.285: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0.000000 % :: OnTime 180132.500000 % :: Late -0.000000 %
10-04 15:38:54.817: ERROR/(1160): This file is not ASF file.
10-04 15:39:32.004: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0 frames :: OnTime 0 frames :: Late 0 frames :: Total 1435 frames
10-04 15:39:32.004: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0.000000 % :: OnTime 90066.250000 % :: Late -0.000000 %
10-04 15:39:32.528: ERROR/(1160): This file is not ASF file.
10-04 15:40:19.552: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0 frames :: OnTime 0 frames :: Late 0 frames :: Total 1808 frames
10-04 15:40:19.552: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0.000000 % :: OnTime 0.000000 % :: Late -0.000000 %
10-04 15:40:20.059: ERROR/(1160): This file is not ASF file.
10-04 15:41:16.371: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0 frames :: OnTime 0 frames :: Late 0 frames :: Total 2163 frames
10-04 15:41:16.371: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0.000000 % :: OnTime 0.000000 % :: Late -0.000000 %
10-04 15:41:16.856: ERROR/(1160): This file is not ASF file.
10-04 15:42:25.340: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0 frames :: OnTime 0 frames :: Late 0 frames :: Total 2629 frames
10-04 15:42:25.340: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0.000000 % :: OnTime 0.000000 % :: Late -0.000000 %
10-04 15:42:25.809: ERROR/(1160): This file is not ASF file.
10-04 15:42:27.286: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0 frames :: OnTime 0 frames :: Late 0 frames :: Total 66 frames
10-04 15:42:27.286: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0.000000 % :: OnTime 0.000000 % :: Late -0.000000 %
10-04 15:42:27.840: ERROR/(1160): This file is not ASF file.
10-04 15:42:55.996: ERROR/GlobalUnplugService(1665): plugged = true,mBatteryPlugged=true
10-04 15:43:19.950: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0 frames :: OnTime 0 frames :: Late 0 frames :: Total 2002 frames
10-04 15:43:19.950: ERROR/ProfileVideoFrameDrops(1160): PVMediaOutputNodePort :: Early 0.000000 % :: OnTime 0.000000 % :: Late -0.000000 %
10-04 15:43:20.418: ERROR/(1160): This file is not ASF file.

[lambda]

I agree, it sucks!

It seems to always skip in the beginning around the same time, every song.

Do any devs ever read this forum ever? I see 95% of questions unanswered.

It is a little dismaying to not even get acknowledgement that this problem is a priority to be fixed, especially given that us users of the Android client paid for this capability.

[sindre_mehus]

Hi guys,

First of all, sorry for being absent from the forum for so long.

I'm not sure why some users get stutters/skips, but it seems to be different from phone to phone. Also, I suspect there could be several issues here.

I haven't seen this problem myself (Nexus One), with one exception: Sometimes when listening to long podcasts (and downloading the same podcast at the same time), the player jumps back a few minutes. It never happens if the podcast is already downloaded.

I'll look into this problem and hopefully come up with something.

Regards
Sindre

[technics2000]

Hi guys,

First of all, sorry for being absent from the forum for so long.

I'm not sure why some users get stutters/skips, but it seems to be different from phone to phone. Also, I suspect there could be several issues here.

I haven't seen this problem myself (Nexus One), with one exception: Sometimes when listening to long podcasts (and downloading the same podcast at the same time), the player jumps back a few minutes. It never happens if the podcast is already downloaded.

I'll look into this problem and hopefully come up with something.

Regards
Sindre

Thank You for replying Sindre!

Just to clarify, the skips only happen when streaming, although if you stream a song and it finishes downloading it will skip as the next track in the queue is downloading.

Also, I don't know if this helps but if I connect using the web interface I can stream over 3g while transcoding flac to 320kbps mp3 without any skipping or stuttering, so it looks like its not a limitation on the phone but something with the app.

Let me know if you need help testing, I have a Droid X and I'd be glad to help.

[alphawave7]

Hi guys,

First of all, sorry for being absent from the forum for so long.

I'm not sure why some users get stutters/skips, but it seems to be different from phone to phone. Also, I suspect there could be several issues here.

I haven't seen this problem myself (Nexus One), with one exception: Sometimes when listening to long podcasts (and downloading the same podcast at the same time), the player jumps back a few minutes. It never happens if the podcast is already downloaded.

I'll look into this problem and hopefully come up with something.

Regards
Sindre

Howdy Sindre!
This may not be a SS issue (Nexus One), as Google Listen often does the same thing to me: I suspect some podcasts have insufficient metadata until they are fully downloaded to allow the player to determine the filesize/length of play, and subsequently 'coughs' during simultaneous playback. Some podcasts have no issue, others that do, I have learned to simply be patient and allow them to d/l entirely...then no issue.

[sigel]

I'm available for testing as well if needed.

T-Mobile Vibrant

Had a friend with his Evo test in my car the other night and it was real bad, but it sounded more like phone lag

[cavediver]

HTC EVO; Subsonic 1.7.1 - The problem I'm having recently is songs will get almost to the end then restart at the beginning over and over, and never skip to the next song. Play all checked. I have to manually select the next song to stop the loop, then the same looping starts over on the next song. Subsonic on my EVO has become virtually unuseable due to this problem.

[sn0skier]

Having the same problem as cave diver as well as the sputtering problem.