1077329 - [WAP push][CP] Delay when closing application

Status: RESOLVED FIXED

(Firefox OS Graveyard :: Gaia::Wappush, defect)

Description

[Albert [:albert]]

When the application is closed there is a considerable delay between user click and app closes.

There is also a problem when closing regarding the UI, the popup disappears and the  last screen is visible while the app closes.

Comment 1

[Gabriele Svelto [:gsvelto]]

(In reply to Albert [:albert] from comment #0)
> When the application is closed there is a considerable delay between user
> click and app closes.
> 
> There is also a problem when closing regarding the UI, the popup disappears
> and the  last screen is visible while the app closes.

Can you provide a more detailed STR? We would need the message contents causing this behavior and the exact interaction steps taken.

If you're testing on an actual device please enable gaia debugging (this can be done by changing the debug.gaia.enabled pref using the edit-prefs.sh script that's in the B2G root directory) and attach the resulting logcat output.

Comment 2

[Albert [:albert]]

STR
1. Send a CP message (USERPIN security)
2. Insert correct PIN
3. Confirm Process Complete Dialog

EXPECTED
Application closes.

ACTUAL
Dialog disappears, pin screen is visible, application closes.

Comment 3

[Albert [:albert]]

(In reply to Gabriele Svelto [:gsvelto] from comment #1)
> (In reply to Albert [:albert] from comment #0)
> > When the application is closed there is a considerable delay between user
> > click and app closes.
> > 
> > There is also a problem when closing regarding the UI, the popup disappears
> > and the  last screen is visible while the app closes.
> 
> Can you provide a more detailed STR? We would need the message contents
> causing this behavior and the exact interaction steps taken.
> 
> If you're testing on an actual device please enable gaia debugging (this can
> be done by changing the debug.gaia.enabled pref using the edit-prefs.sh
> script that's in the B2G root directory) and attach the resulting logcat
> output.

debug.gaia.enabled doesn't show helpful traces. I added some 'dump' in wpm_close

  var time = 0;

  function wpm_close() {
    if (time == 0) {
      time = Date.now();
    }

    dump("-- " + (Date.now() - time) + " -- wpm_close -- \n");
    if (closeTimeout !== null) {
      dump("-- " + (Date.now() - time) + " -- wpm_close timeout not null -- \n");
      // We're already trying to close the app
      return;
    }

    /* We do not close the app immediately, instead we spin the event loop once
     * in the hope of catching pending messages that have been sent to the app
     * and have not yet been processed. If some messages are pending we'll
     * reschedule the close until they've all been processed. */
    dump("-- " + (Date.now() - time) + " -- wpm_close call setTimeout -- \n");
    closeTimeout = window.setTimeout(function wpm_delayedClose() {
      dump("-- " + (Date.now() - time) + " -- delayedClose -- \n");
      if (pendingMessages > 0) {
        dump("-- " + (Date.now() - time) + " -- delayed_close pending messages -- \n");
        // Pending messages were received since we set this timer
        closeTimeout = window.setTimeout(wpm_delayedClose, 100);
        return;
      }

      /* There's no more pending messages and the application is in the
       * background, close for real */
      DUMP('Automatically closing the application');
      closeTimeout = null;

      dump("-- " + (Date.now() - time) + " -- delayed_close call closed -- \n");
      window.close();
      dump("-- " + (Date.now() - time) + " -- delayed_close closed called -- \n");
    }, 100);
  }

and I get the following:

I/GeckoDump( 9959): -- 0 -- wpm_close -- 
I/GeckoDump( 9959): -- 1 -- wpm_close call setTimeout -- 
I/GeckoDump( 9959): -- 102 -- delayed_close --
I/GeckoDump( 9959): [wappush] Automatically closing the application
I/GeckoDump( 9959): -- 102 -- delayed_close call closed -- 
I/GeckoDump( 9959): -- 104 -- delayed_close closed called -- 
I/GeckoDump( 9959): -- 472 -- wpm_onVisibilityChange -- 
I/GeckoDump( 9959): -- 473 -- wpm_onVisibilityChange  call close -- 
I/GeckoDump( 9959): -- 473 -- wpm_close -- 
I/GeckoDump( 9959): -- 473 -- wpm_close call setTimeout --
W/WAP Push manager( 9959): [JavaScript Error: "IndexedDB UnknownErr: IDBDatabase.cpp:779"]

There is a 368ms delay since the call to window.close() until the application is closed. The last indexedDB error can be the cause? Any advice?

Comment 4

[Albert [:albert]]

I removed the database of the flow to discard problems but the delay persists. I also made a test application with only a button calling window.close() and the result is the same, there is a delay of 375ms since the call to close until the app is really closed. So it seems to be something related to gecko and not a problem of the wappush application.

I'm going to remove the call to hide the dialog screen so the user doesn't feel confused.

Comment 5

[Albert [:albert]]

Attachment: Patch

Comment 6

[Gabriele Svelto [:gsvelto]]

(In reply to Albert [:albert] from comment #4)
> I removed the database of the flow to discard problems but the delay
> persists.

Before I review your patch have you figured out what is causing the database error? I'd like that to be fixed first before we work around the delay.

Comment 7

[Albert [:albert]]

(In reply to Gabriele Svelto [:gsvelto] from comment #6)
> (In reply to Albert [:albert] from comment #4)
> > I removed the database of the flow to discard problems but the delay
> > persists.
> 
> Before I review your patch have you figured out what is causing the database
> error? I'd like that to be fixed first before we work around the delay.

I saw the same error before start refactoring the whole application, for that reason I didn't think it was important. I would prefer to open a new bug to see what's happening with the database so we can close the remaining bugs that are blocking the certification process (1077329 and 1067296). What do you think?

Comment 8

[Gabriele Svelto [:gsvelto]]

Comment on attachment 8501538 [details] [review]
Patch

(In reply to Albert [:albert] from comment #7)
> I saw the same error before start refactoring the whole application, for
> that reason I didn't think it was important. I would prefer to open a new
> bug to see what's happening with the database so we can close the remaining
> bugs that are blocking the certification process (1077329 and 1067296). What
> do you think?

I agree; in fact I think that the error you're seeing is not really an error. IndexedDB has changed the way it reports errors recently and it has become a lot more verbose so we might be having a false positive here.

Comment 9

[Albert [:albert]]

Master: https://github.com/mozilla-b2g/gaia/commit/4612effd9d42d4b03d4c549191b9a2934e60f864