App freezes when item on playlist finishes

[GoogleCodeExporter]

App freezes when item on playlist finishes

[GoogleCodeExporter]

This sounds similar to what happens in cases where the app is waiting for the 
MediaPlayer to prepare and it never does (such as when a media stream is 
invalid at the start), which is fixed in development (r100) but not in a 
released version (or version_1.x branch). However, off-hand I don't know why 
that would fire when skipping to the next item in a playlist.

There have been a number of recent changes to how playlists are handled. Can 
you tell us which version of the app you are running?

Original comment by [email protected] on 28 Sep 2010 at 8:57

[GoogleCodeExporter]

I added a separate issue 42 for your concern about finding this project site. 
Note that the app does have a feedback button, so we'll discuss on the list 
whether more details are needed.

Original comment by [email protected] on 28 Sep 2010 at 9:03

[GoogleCodeExporter]

Thanks Greg!

In the upcoming 2.0 release, the playlist functionality (and I believe backend 
as well) will be completely revamped.  Hopefully if this issue isn't fixed in 
the next production release it will be a non-issue in the near future.

Congrats on taking the open source plunge :)

Original comment by [email protected] on 29 Sep 2010 at 1:20

• Changed state: Accepted

[GoogleCodeExporter]

Anyone seen this reproduced post 2.0 launch?

Original comment by [email protected] on 19 Apr 2011 at 9:29

[GoogleCodeExporter]

First let me thank you all for an application that I use many hours a day every 
day.

To answer the question in comment 4 ... Yes, I see the "freeze after item 
finishes playing" behavior on a regular basis.  The behavior occurs 
intermittently and unpredictably, not seeming to have any connection with what 
tasks are running or what the user is doing with the phone.  From Android 
marketplace user comments, it appears many users are continuing to experience 
this problem. My phone is a Motorola Droid 1, running the 2.2.2 OS.  

In my environment, I often use WiFi connectivity, and I know my Comcast 
Internet connection often drops out for a few seconds at a time, with browser 
requests needing to be retried.  That may be a difference between my 
environment and yours.  So you may be able to reproduce this if you set your 
phone to airplane mode, connect via WiFi, and interrupt the WiFi for a short 
time.  Or try the test at someone's house with similarly low-quality Internet 
service :-)

Since you already have a RC for 2.1, I'm entering this now just to document 
that the problem is still there as of 2.0.2.  I'll report again when 2.1 is 
available. Hopefully, other work you've done may have addressed the underlying 
issue.

Best,
Dan

Original comment by [email protected] on 1 Jul 2011 at 5:01

[GoogleCodeExporter]

I tried the 2.1 RC release today, and unfortunately this issue was not 
resolved.  After playing an item, the application would sometimes become 
unresponsive, displaying the "not responding / Force Close" dialog.  At other 
times, after playing an item, the title of the next story would be displayed, 
the loading indicator would begin animation, but the story would not play and 
there would be no indication of a problem.

After confirming the problem occurred several times, I installed LogCollector, 
waited for the playlist to stop playing, and captured the attached log.  In 
this case, when the playlist stopped playing, a Toast of the msg_playback_error 
string was displayed. This was interesting because it was actually the *first* 
time that I have seen this display in the many the months of failures that 
occurred before I installed LogCollector. (I.e., the message did not display 
when I first installed the 2.1 RC, only after installing LogCollector.)

The playback failure occurred at approximately 8:58.  This was three minutes 
after the network entered the DISCONNECTED/IDLE state at 8:55. The player was 
playing the previously-retrieved story at the time.

At the start of the /dev/log/main capture -- 8:58:09 -- the application was 
already cycling through the playlist, attempting to play each one three times 
and failing due to an IOException in retrieving the playlist.  You can see that 
the failure is happening very quickly, often less than 20 milliseconds between 
attempts.  Network connectivity was restored at 8:58:43, too late for the retry 
logic.

This suggests a straightforward fix: test for network connectivity as part of 
the IOException error handling.  If there is no connectivity, enter a loop 
where you generate a Toast message, sleep, and test again. You will need 
android.permission.ACCESS_WIFI_STATE to do that.

So what about the unresponsive app scenario?  I will keep watching for that.  
One observation is that since PlaybackService.OnDestroy has a synchronized 
(this) block, if it is ever executed from within one of the many synchronized 
methods or blocks in the rest of the logic, a deadlock will occur.

Thanks again for your work on an extremely valuable app.

Best,
Dan

Original comment by [email protected] on 5 Jul 2011 at 6:35

Attachments:

• [Android device log all.txt](https://storage.googleapis.com/google-code-attachments/npr-android-app/issue-41/comment-6/Android device log all.txt)

[GoogleCodeExporter]

In the 2.1 RC, I was able to replicate a second variant of the "player does not 
respond correctly" behavior:
1) The player finishes playing an item for which there are no subsequent items. 
2) The spinner is activated, but no story plays.
3) Selecting other stories in the playlist causes the title to be displayed but 
nothing is played.
4) After several minutes with no user interaction, a story begins to play.

The following three logs were captured at three different times: immediately 
after the player stopped playing, during the period where UI selection of other 
stories did not cause them to play, and after playing spontaneously resumed. 

In the first log file, the entries at 12:23:21.580 were generated after playing 
the last unread playlist item.  At 12:23:33.354, "Unexpected resume of 
org.npr.android.news while already resumed in org.npr.android.news".  At 
12:23:54.041, a new instance of PlaybackService was created, 
PlaybackService.onStart was called, and a download was attempted, but nothing 
was played.  At 12:24:02.510, PlaybackService.onStart was entered again, this 
time without any preceding PlaylistProvider log messages, but no subsequent 
actions were logged and nothing was played.

In the second log file, there are repeated calls of PlaybackService.onStart 
following several interactions with the UI.  None of these caused any other 
actions to be logged, and nothing was played.

In the third log file, the entries at 12:27:39.557, generated by 
PlaylistService.prepareThenPlay, were triggered without any UI interaction.  
This starts the sequence of events that leads to a story being played.

Original comment by [email protected] on 5 Jul 2011 at 10:23

Attachments:

• [Android device log hung.txt](https://storage.googleapis.com/google-code-attachments/npr-android-app/issue-41/comment-7/Android device log hung.txt)
• [Android device log still hung.txt](https://storage.googleapis.com/google-code-attachments/npr-android-app/issue-41/comment-7/Android device log still hung.txt)
• [Android device log resumed.txt](https://storage.googleapis.com/google-code-attachments/npr-android-app/issue-41/comment-7/Android device log resumed.txt)

[GoogleCodeExporter]

This is a log from a situation where after finishing playing an item, the UI 
does not respond to any input, and the not responding / force close dialog is 
displayed.

In this log, the playback stopped at 18:01, and the attempt to use the UI which 
triggered the ANR dialog occurred at 18:02:02.720.  Since nothing unusual seems 
to have been reported, a deadlock involving the various synchronization blocks 
in PlaybackService methods would certainly be a leading possibility.

This is the last submission I plan to do for a while. Looking back on the three 
reports today, probably the previous two should have been treated as two new 
issues.  Only this current submission really deals with the same behavior as 
the one originally reported last year by Greg.

Original comment by [email protected] on 6 Jul 2011 at 2:53

Attachments:

• [Android device log anr.txt](https://storage.googleapis.com/google-code-attachments/npr-android-app/issue-41/comment-8/Android device log anr.txt)

[GoogleCodeExporter]

Adding this for review in 2.2 milestone.

Original comment by [email protected] on 18 Oct 2011 at 7:47

• Added labels: Milestone-2.2, Priority-High
• Removed labels: Priority-Medium

[GoogleCodeExporter]

Original comment by [email protected] on 7 Dec 2011 at 5:49

• Changed state: Started

[GoogleCodeExporter]

These look like connection issues that will be fixed using the improved error 
handling code.

Original comment by [email protected] on 21 Dec 2011 at 4:05

• Changed state: Fixed

[GoogleCodeExporter]

Original comment by [email protected] on 10 Jan 2012 at 12:28

• Changed state: Verified