920507 - Uncaught exception / crash when Clear private data -> Browsing & download history

Status: VERIFIED FIXED

(Firefox for Android Graveyard :: General, defect)

Description

[Mark Capella [:capella]]

STR the below:

1)   Navigate to the About:home HISTORY page, "Most Recent" tab
2)   Ensure there is History under "Today" and "Yesterday"

3)   You can create entries for "Yesterday" by:
        Android Menu -> Settings -> Date and time
        Set date to yesterday
        Return to FF and navigate to a page
        Switch back to Android Date and time and reset the correct date
        Return to FF About:home HISTORY page, "Most Recent" tab

4) Tap menu -> Settings -> Privacy -> Clear private data -> Check Browsing & download history ... tap Clear data
5) Tap Back -> to Settings Page
6) Tap Back -> About:History ....

>Boom<


E/GeckoAppShell( 9296): java.lang.IllegalStateException: Couldn't move cursor to position 0
E/GeckoAppShell( 9296): 	at org.mozilla.gecko.home.MultiTypeCursorAdapter.getCursor(MultiTypeCursorAdapter.java:49)
E/GeckoAppShell( 9296): 	at org.mozilla.gecko.home.MostRecentPage$MostRecentAdapter.bindView(MostRecentPage.java:255)
E/GeckoAppShell( 9296): 	at org.mozilla.gecko.home.MultiTypeCursorAdapter.getView(MultiTypeCursorAdapter.java:62)
E/GeckoAppShell( 9296): 	at android.widget.AbsListView.obtainView(AbsListView.java:2437)
E/GeckoAppShell( 9296): 	at android.widget.ListView.makeAndAddView(ListView.java:1775)
E/GeckoAppShell( 9296): 	at android.widget.ListView.fillDown(ListView.java:678)
E/GeckoAppShell( 9296): 	at android.widget.ListView.fillSpecific(ListView.java:1336)
E/GeckoAppShell( 9296): 	at android.widget.ListView.layoutChildren(ListView.java:1606)
E/GeckoAppShell( 9296): 	at android.widget.AbsListView.onLayout(AbsListView.java:2288)
E/GeckoAppShell( 9296): 	at android.view.View.layout(View.java:13957)
E/GeckoAppShell( 9296): 	at android.view.ViewGroup.layout(ViewGroup.java:4374)
E/GeckoAppShell( 9296): 	at android.widget.LinearLayout.setChildFrame(LinearLayout.java:1655)
E/GeckoAppShell( 9296): 	at android.widget.LinearLayout.layoutVertical(LinearLayout.java:1513)
E/GeckoAppShell( 9296): 	at android.widget.LinearLayout.onLayout(LinearLayout.java:1426)
E/GeckoAppShell( 9296): 	at android.view.View.layout(View.java:13957)

Comment 1

[Mark Capella [:capella]]

Attachment: bug920507 (v0)

This fixes the problem ... (it's my first thought) ... does the approach look ok to you?

Comment 2

[Mark Capella [:capella]]

I usually ask margaret to stay in the loop with my stuff ... adding her to the cc:

Comment 3

[Mark Capella [:capella]]

I guess I should have elaborated, but I just figured sriram would already know ... when the history sanitize removes the db entries it leaves the |mMostRecentSections| table populated
http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/home/MostRecentPage.java#218

This throws off the subsequent getCount() return values
http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/home/MostRecentPage.java#248

Comment 4

[Sriram Ramasubramanian [:sriram]]

Comment on attachment 810068 [details] [diff] [review]
bug920507 (v0)

Review of attachment 810068 [details] [diff] [review]:
-----------------------------------------------------------------

This looks good to me.

::: mobile/android/base/home/MostRecentPage.java
@@ +5,5 @@
>  
>  package org.mozilla.gecko.home;
>  
>  import org.mozilla.gecko.R;
> +import org.mozilla.gecko.GeckoAppShell; 

White space.

Comment 5

[Mark Capella [:capella]]

Attachment: bug920507 (v1)

TRY push... https://tbpl.mozilla.org/?tree=Try&rev=5c48e5275f45
and approval request ...

Comment 6

[Mark Capella [:capella]]

Attachment: bug920507Synch

I had another thought ... if we do it this way, we achieve the same result ... it follows the object hierchy and is a synchronous process, whereas the first version depends on the initial message/trigger being heard and processed in two places ...

Comment 7

[Mark Capella [:capella]]

Comment on attachment 811745 [details] [diff] [review]
bug920507Synch

Changing feedback request to lucasr at srirams suggestion re: fragments

fyi, we're trying to avoid a crash situation, root cause understood, two approaches each will solve it ...

Comment 8

[Lucas Rocha (:lucasr)]

Comment on attachment 811745 [details] [diff] [review]
bug920507Synch

Review of attachment 811745 [details] [diff] [review]:
-----------------------------------------------------------------

If the goal here is to simply clear the history sections map when history is cleared, the solution can probably be much simpler than this. Besides, you should be careful with how you interact with fragments as their state are managed by the platform and might not necessarily be in the state you expect at any given time.

When the DB entries are all removed, the cursor will/should be automatically refreshed by the matching loaders attached to each live fragment. Have you checked the sequence of calls that happen when history is cleared? This line was added to handle a similar issue in the past (can't remember the bug number now):

http://mxr.mozilla.org/mozilla-central/source/mobile/android/base/home/MostRecentPage.java#317

Bottom line is: we should be able to fix this bug by simply ensuring that we're properly clearing the state of the fragments when their loaders get refreshed. For instance, are onLoadFinished and onLoaderReset being called when history is cleared? If the loaders are not getting refreshed when history is cleared then we have to understand why.

Comment 9

[Mark Capella [:capella]]

Attachment: bug920507Simple

Awesome! New code area for me, but that pointed me towards this new idea:

Stacktrace through MostRecentPage.java in the abend situation / before fix:

<--- About to open About:Home HISTORY MOST RCENT

  (15225): MostRecentPage() CONSTRUCTED
  (15225): onAttach() START
  (15225): onCreateView() START
  (15225): onViewCreated() START
  (15225): onViewCreated() FINISH
  (15225): onActivityCreated() START
  (15225): MostRecentAdapter - CONSTRUCTED
  (15225): load() START
  (15225): CursorLoaderCallbacks - onCreateLoader() START
  (15225): MostRecentCursorLoader - CONSTRUCTED
  (15225): MostRecentCursorLoader - loadCursor() START
  (15225): MostRecentCursorLoader - loadCursor() FINISH
  (15225): CursorLoaderCallbacks - onLoadFinished() START
  (15225): MostRecentAdapter - swapCursor()
  (15225): MostRecentAdapter - loadMostRecentSections()
  (15225): CursorLoaderCallbacks - onLoadFinished()    MIDDLE
  (15225): updateUiFromCursor() START
  (15225): CursorLoaderCallbacks - onLoadFinished() FINISH
  (15225): MostRecentAdapter - bindView()
  (15225): MostRecentAdapter - bindView()
  (15225): MostRecentAdapter - bindView()
  (15225): MostRecentAdapter - bindView()
  (15225): MostRecentAdapter - bindView()

<--- About to tap menu -> Settings -> Privacy -> Clear private data -> Clear data button
<--- "Private data cleared" toast is observed, we're back to Privacy Screen
<--- About to tap BACK
<--- We're back to Settings Screen
<--- About to tap BACK

  (15225): MostRecentCursorLoader - loadCursor() START
  (15225): MostRecentCursorLoader - loadCursor() FINISH
  (15225): MostRecentAdapter - bindView()
  (15225): MostRecentAdapter - bindView()

!!! Here we crash ... the two bindViews() are called due to
!!! Wrong getCount() return value factoring in the (now erroneous) section headers


So if we apply the patch and clear the section headers during the loadCursor() call when the fragment is being re-displayed / reloaded ...

<--- About to open About:Home HISTORY MOST RCENT

  (15887): MostRecentPage() CONSTRUCTED
  (15887): onAttach() START
  (15887): onCreateView() START
  (15887): onViewCreated() START
  (15887): onViewCreated() FINISH
  (15887): onActivityCreated() START
  (15887): MostRecentAdapter - CONSTRUCTED
  (15887): load() START
  (15887): CursorLoaderCallbacks - onCreateLoader() START
  (15887): MostRecentCursorLoader - CONSTRUCTED
  (15887): MostRecentCursorLoader - loadCursor() START
  (15887): MostRecentCursorLoader - loadCursor() FINISH
  (15887): CursorLoaderCallbacks - onLoadFinished() START
  (15887): MostRecentAdapter - swapCursor()
  (15887): MostRecentAdapter - loadMostRecentSections()
  (15887): CursorLoaderCallbacks - onLoadFinished()    MIDDLE
  (15887): updateUiFromCursor() START
  (15887): CursorLoaderCallbacks - onLoadFinished() FINISH
  (15887): MostRecentAdapter - bindView()
  (15887): MostRecentAdapter - bindView()
  (15887): MostRecentAdapter - bindView()
  (15887): MostRecentAdapter - bindView()
  (15887): MostRecentAdapter - bindView()

<--- About to tap menu -> Settings -> Privacy -> Clear private data -> Clear data button
<--- "Private data cleared" toast is observed, we're back to Privacy Screen
<--- About to tap BACK
<--- We're back to Settings Screen
<--- About to tap BACK

  (15887): MostRecentCursorLoader - loadCursor() START
  (15887): MostRecentCursorLoader - loadCursor() FINISH

  (15887): CursorLoaderCallbacks - onLoadFinished() START
  (15887): MostRecentAdapter - swapCursor()
  (15887): MostRecentAdapter - loadMostRecentSections()
  (15887): CursorLoaderCallbacks - onLoadFinished()    MIDDLE
  (15887): updateUiFromCursor() START
  (15887): CursorLoaderCallbacks - onLoadFinished() FINISH

!!! Here we don't crash / all is unicorns and enchanted bunnies ...

Comment 10

[Lucas Rocha (:lucasr)]

Comment on attachment 812636 [details] [diff] [review]
bug920507Simple

Review of attachment 812636 [details] [diff] [review]:
-----------------------------------------------------------------

Every time a loader is auto-refreshed, it will first call onLoaderReset() (on the UI thread) and then run the query again. In onLoaderReset() we call mAdapter.swapCursor(null). It seems to me that the actual issue here is that mMostRecentSections.clear() is not called when we pass a null cursor loadMostRecentSections(). Moving mMostRecentSections.clear() to be unconditionally called before the early return for null/empty cursors should probably fix this bug, I think.

::: mobile/android/base/home/MostRecentPage.java
@@ +42,5 @@
>      // Cursor loader ID for history query
>      private static final int LOADER_ID_HISTORY = 0;
>  
>      // Adapter for the list of search results
> +    private static MostRecentAdapter mAdapter;

Hmm, this might cause a bunch of subtle bugs and it's not meant to be static anyway.

@@ +143,5 @@
>  
>          @Override
>          public Cursor loadCursor() {
> +            // Clear mAdapter's recent sections array, ensure accurate bindView(), getCount(), etc
> +            mAdapter.clearMostRecentSections();

This is probably not the right place to do it because loadCursor() is called off main thread. mMostRecentSections affects the adapter's getCount() value and should only be updated in the UI thread.

Comment 11

[Mark Capella [:capella]]

mmm.... tried that and it failed ... I should have realized as I already have debug code in onLoaderReset() in the fragment, and don't see that it's being triggered in either the failing or corrected log traces posted above ... 

I'll look some more ... this means then that either the Sanitize:History isn't triggering a call to onLoaderReset(), or the fragment doesn't hear it being offscreen (?) ...

Comment 12

[Mark Capella [:capella]]

I wonder if |Every time a loader is auto-refreshed, it will first call onLoaderReset()| is accurate.

I found "The CursorLoaderCallbacks onLoaderReset(Loader) method gets called when your loader's callback (usually an Activity or Fragment instance) is asked to release all references to the Cursor which it has gained via onLoadFinished(Loader, Cursor)"
http://stackoverflow.com/questions/12937060/loaders-and-onloaderreset-android

Reading the class source, this seems to occur when the fragments LoaderManager LoaderInfo.destroy() method is invoked, which doesn't happen in my testing between when the MostRecentPage fragments onPause()/onStop() call is followed by the Settings page load, and the subsequent return to MostRecentPage and its onStart()/onResume() methods.

What does happen on return from the Settings page is that the MostRecentCursorLoader loadCursor() is triggered to rebuild the MostRecentPage fragment fresh, and then the error condition happens where the history cursor has been cleared, but getCount() thinks there's two items available (the section headers from before), and we try to query the database for items to bind to the view that don't exist.

While loadCursor() is called off main thread, and clearing the mMostRecentSections array will affect the adapter's getCount() value, that doesn't occur until (I think) we're back onto the UI thread and trying to bind the views which I think is what we want.

I guess next I'd have to wonder why making mAdapter static is a bad thing ? We only assign it once at onActivityCreated() and the class is a single instance (?)

Comment 14

[Mark Capella [:capella]]

Comment on attachment 812636 [details] [diff] [review]
bug920507Simple

So, I'm waiting for feedback here ... wondering which way to go favoring the last one in my mind ...

Fragments in stopped state (off screen while overlayed by another fragment) don't seem to be receiving UI cursor callbacks until they return to active status and the whole UI is re-generated like activity destroy()/create() ...

So somwhere along the line we need to inctercept the fact that the cursor was reset by the "Sanitize:History" message so getCount() returns valid values before the listadapter is rebuilt.

Comment 15

[Lucas Rocha (:lucasr)]

(In reply to Mark Capella [:capella] from comment #14)
> Comment on attachment 812636 [details] [diff] [review]
> bug920507Simple
> 
> So, I'm waiting for feedback here ... wondering which way to go favoring the
> last one in my mind ...
> 
> Fragments in stopped state (off screen while overlayed by another fragment)
> don't seem to be receiving UI cursor callbacks until they return to active
> status and the whole UI is re-generated like activity destroy()/create() ...
> 
> So somwhere along the line we need to inctercept the fact that the cursor
> was reset by the "Sanitize:History" message so getCount() returns valid
> values before the listadapter is rebuilt.

Debugged this a bit. My assumption about onLoaderReset was actually not accurate, as you pointed out. When the cursor data is refreshed, the loader will actually call force re-loading and completely bypass onLoaderReset. So, you probably just need to:

1. Change loadMostRecentSections() to clear mMostRecentSections unconditionally i.e. move the clear call to the top.
2. Override onForceLoad() in MostRecentCursorLoader, call loadMostRecentSections(null) in there.

That should work, I think.

Comment 16

[Mark Capella [:capella]]

Attachment: bug920507Nice

Yep - we're getting there !

This is the best patch so far, though we still require the static MostRecentAdapter ...

Comment 17

[Lucas Rocha (:lucasr)]

Comment on attachment 816809 [details] [diff] [review]
bug920507Nice

Review of attachment 816809 [details] [diff] [review]:
-----------------------------------------------------------------

Turning the adapter into a static member is not correct by definition (the adapter is part of the fragment instance state, not the fragment class). What we probably need here is a way (a listener in the custom loader maybe?) to track when the loader is forced to reload. Just be careful as the loader's life cycle is controlled by the platform e.g. when you rotate the device, the same loader instance is kept in memory but the fragment dependencies (adapter, views, etc) are re-created.

Another (maybe simpler) option might be to reset the loader (i.e. call reset()) in the Loader's onForceLoad() as this would ensure onLoaderReset() is called. You'd still need the change to call clear mMostRecentSections unconditionally. I'm not entirely sure about the potential side-effects of this approach but it's definitely worth trying.

::: mobile/android/base/home/MostRecentPage.java
@@ +316,5 @@
>          }
>  
>          private void loadMostRecentSections(Cursor c) {
> +            // Clear any history sections that may have been loaded before.
> +            mMostRecentSections.clear();

nit: add empty line here.

Comment 18

[Mark Capella [:capella]]

Attachment: bug920507Logical

No, that hurts my brain. What if I stop thinking so hard and just do this?

Comment 19

[Chenxia Liu [:liuche]]

Popping in from bug 919227, can you make sure that manually removing all the history items (long-press on item and "Remove") does not cause a crash? You may need to add a mAdapter.notifyDataSetChanged() call somewhere.

Comment 20

[Mark Capella [:capella]]

If you're asking me, I did that already and it works fine as commented in bug 919227  :-)

Comment 21

[Chenxia Liu [:liuche]]

Great, thanks capella!

Comment 22

[Lucas Rocha (:lucasr)]

Comment on attachment 817261 [details] [diff] [review]
bug920507Logical

Review of attachment 817261 [details] [diff] [review]:
-----------------------------------------------------------------

As per discussion on IRC, let's try to find a way to handle this in such was that we always clear mMostRecentSections when the cursor is replaced in the adapter. This patch might be a good option as a last resort if a cleaner solution is not really possible here.

Comment 23

[Mark Capella [:capella]]

Attachment: bug920507 Duh

This works, and solves for |let's try to find a way to handle this in such was that we always clear mMostRecentSections when the cursor is replaced in the adapter|

The bit of code changed at the bottom in loadMostRecentSections() is just cleanup I think we both agree is better, but is not actually required for this bug.

Don't ask me why it took 5 different patches to find a one line fix... I'm already embarrased.

Comment 24

[Lucas Rocha (:lucasr)]

Comment on attachment 819064 [details] [diff] [review]
bug920507 Duh

Review of attachment 819064 [details] [diff] [review]:
-----------------------------------------------------------------

Also, make sure that this patch covers the case described in comment #c19

::: mobile/android/base/home/MostRecentPage.java
@@ +235,5 @@
>          }
>  
>          @Override
>          public Cursor swapCursor(Cursor cursor) {
> +            mMostRecentSections.clear();

As per discussion on IRC, let's remove this clear() call here and just move loadMostRecentSections() to be called before super.swapCursor() here.

Comment 25

[Mark Capella [:capella]]

yah, if we're moving the mMostRecentSections.clear(); up in loadMostRecentSections() anyhow so that it's always performed, then we can just do the call to loadMostRecentSections(cursor); before the swapCursor() ...

and I already checked comment #19 and it's still good ... patch inna bit ...

Comment 26

[Mark Capella [:capella]]

Attachment: bug920507 Doh!

:-) Well I took the long way around and learned a lot about fragment infrastructure in the process ...

Comment 28

[Lucas Rocha (:lucasr)]

Comment on attachment 819107 [details] [diff] [review]
bug920507 Doh!

Review of attachment 819107 [details] [diff] [review]:
-----------------------------------------------------------------

Nice. Did you check if this patch also fixes bug 919227?

Comment 29

[Mark Capella [:capella]]

Yes, comment #19 was re: bug919227 and it works great! 

btw, apologies go to liuche as we converged on the same problem, that was being observed in two different bugs / manners ...

Comment 30

[Mark Capella [:capella]]

TRY looks good https://tbpl.mozilla.org/?tree=Try&rev=89b2b4ea1422

Comment 31

[Mark Capella [:capella]]

Saving the world, one bug at a time ... 
https://hg.mozilla.org/integration/fx-team/rev/eeee2c0ca5ff

Comment 32

[Phil Ringnalda (:philor)]

https://hg.mozilla.org/mozilla-central/rev/eeee2c0ca5ff

Comment 33

[Lucas Rocha (:lucasr)]

Capella, please request uplift to Aurora.

Comment 34

[Mark Capella [:capella]]

Comment on attachment 819107 [details] [diff] [review]
bug920507 Doh!

[Approval Request Comment]
Bug caused by (feature/regressing bug #): new about:home implementation
User impact if declined: Crashes .... doom, despair
Testing completed (on m-c, etc.): local machine, verified in m-c by aaraonmt
Risk to taking this patch (and alternatives if risky): small, fix extremely well understood, backup simple
String or IDL/UUID changes made by this patch: None

Comment 35

[Lukas Blakk [:lsblakk] use ?needinfo]

I assume this is actually still affected on FF26 since it hasn't been uplifted yet.

Comment 36

[Lucas Rocha (:lucasr)]

https://hg.mozilla.org/releases/mozilla-aurora/rev/ff149163d8e0