1034490 - Usage app takes 30sec+ to display usage

Status: VERIFIED FIXED

(Firefox OS Graveyard :: Gaia::Cost Control, defect)

Description

[:gerard-majax]

After the fix for bug 1017581 landed, I can now get access to the usage plot.

However, it takes more than 30 secs to display the plot, but the rest of the UI is there.

This is constantly reproducing on my Nexus S.

Comment 1

[bhavana bajaj [:bajaj]]

NI, marina here to get started here, 30 secs does seem too long for the data to load? How have we performed in past releases (1.3/1.4)?

Comment 2

[Marina Rodríguez [:mai]]

Hi,
I've been testing with my devices, and I cannot reproduce it.

Comment 3

[:gerard-majax]

Marina, have you ever thought this may come from my data ?

Comment 4

[:gerard-majax]

Attachment: 2014-07-07-11-31-26.png

Getting this one took nearly one minute.

Comment 5

[Marina Rodríguez [:mai]]

After talking with Alexandre, it's possible the problem it is the volume of data. I'm going to test and try to reproduce his scenario.

Comment 6

[:gerard-majax]

Just to clarify, there is no hack here, just an old profile that I've been migrating over and over. It makes sense since I want to have an overview of the evolution in my data usage over time.

Comment 7

[Pi Wei Cheng [:piwei] (inactive)]

Unable to reproduce the issue on Flame 2.0 and Flame 2.1 master. Usage app correctly displays usage graph immediately upon accessing.

On 2.1 I tested with 25.92MB Mobile usage & 45.74MB Wifi usage.
On 2.0 I tested with 29.01MB Mobile usage & 51.66MB Wifi usage.

Tested on:
Device: Flame
Build ID: 20140707060819
Gaia: 99f56d9db3cd37c684b01de6fed786421f47e2b7
Gecko: 085eea991bb9
Version: 33.0a1 (Master)
Firmware Version: v122
User Agent: Mozilla/5.0 (Mobile; rv:33.0) Gecko/33.0 Firefox/33.0

Device: Flame
Build ID: 20140707130133
Gaia: e935f4ff190b76c70d9b2af8856c542a6e4a7546
Gecko: 3f9d7a3a0b7b
Version: 32.0a2 (2.0)
Firmware Version: v122
User Agent: Mozilla/5.0 (Mobile; rv:32.0) Gecko/32.0 Firefox/32.0

Comment 8

[bhavana bajaj [:bajaj]]

QA is unable to reproduce this , gerard, may be its profile specific ?

Comment 9

[Jason Smith [:jsmith]]

Without proof of this happening on a production device, I don't think we can block on this.

Comment 10

[Marcelino Veiga Tuimil [:sonmarce]]

Marina and Albert are trying to reproduce it by means of a pre-filled database containing several months of data usage, because as Marina said in comment 5 maybe it could be related to the amount of data stored

Comment 11

[Marina Rodríguez [:mai]]

Attachment: patch for testing

Hi Alexandre,
would you mind install the patch and paste the console.log traces. We want to confirm if the problem is on the database query or on the transformation of the data.
Regards

Comment 12

[:gerard-majax]

(In reply to marina rodríguez [:mai] from comment #11)
> Created attachment 8453606 [details] [diff] [review]
> patch for testing
> 
> Hi Alexandre,
> would you mind install the patch and paste the console.log traces. We want
> to confirm if the problem is on the database query or on the transformation
> of the data.
> Regards

Sure, I'll update my dogfooding device and apply this to find out. Keeping the needinfo so I don't forget.

Comment 13

[:gerard-majax]

07-10 11:11:59.853   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:509 in requestDataStatistics: get Samples for mobile [phone]
07-10 11:11:59.860   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:516 in requestDataStatistics: get Samples for wifi 1404983519810
07-10 11:11:59.993   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:459 in checkForCompletion: Get done 1404983519930
07-10 11:11:59.997   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:509 in requestDataStatistics: get Samples for mobile [phone]
07-10 11:12:00.001   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:516 in requestDataStatistics: get Samples for wifi 1404983519981
07-10 11:12:27.118   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:459 in checkForCompletion: Get done 1404983547099
07-10 11:12:41.271   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:459 in checkForCompletion: Get done 1404983561199
07-10 11:12:41.275   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:468 in updateDataUsage: Adapt Data for wifi data: 1404983561201
07-10 11:12:41.275   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:471 in updateDataUsage: Adapt Data for wifi get done: 1404983561206
07-10 11:12:41.275   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:472 in updateDataUsage: Adapt Data for mobile data: 1404983561206
07-10 11:12:41.275   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:475 in updateDataUsage: Adapt Data for mobile data done: 1404983561210
07-10 11:12:41.278   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:459 in checkForCompletion: Get done 1404983561237
07-10 11:12:41.278   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:468 in updateDataUsage: Adapt Data for wifi data: 1404983561237
07-10 11:12:41.278   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:471 in updateDataUsage: Adapt Data for wifi get done: 1404983561240
07-10 11:12:41.278   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:472 in updateDataUsage: Adapt Data for mobile data: 1404983561240
07-10 11:12:41.282   552   552 E GeckoConsole: Content JS LOG at app://costcontrol.gaiamobile.org/js/costcontrol.js:475 in updateDataUsage: Adapt Data for mobile data done: 1404983561243

Comment 14

[Marina Rodríguez [:mai]]

After analyzing your logs, it seems the problems is related with the getSamples  method of the networksStats API. Could be a database problem.
I'm going to assign the bug to Albert.
Regards

Comment 15

[Albert [:albert]]

The root cause of the bug is the 'saveStats' function in the NetworkStatsDB.jsm [1], which is called before filtering for the requested data in order to update the database with the last stats values.

'saveStats' opens a cursor and goes through each value of the database until we find a value with the same 'appId' and 'serviceType' than the updated record that should be stored. When the database is small there is no problem, but for a large database there is a considerable lag. Using Alexander's db file in hamachi it takes one minute.

From my point of view, we can add an index to indexedDB to avoid going across the whole records.

Are you agree?

[1] https://mxr.mozilla.org/mozilla-central/source/dom/network/src/NetworkStatsDB.jsm#361

Comment 16

[John Shih]

(In reply to Albert [:albert] from comment #15)
> The root cause of the bug is the 'saveStats' function in the
> NetworkStatsDB.jsm [1], which is called before filtering for the requested
> data in order to update the database with the last stats values.
> 
> 'saveStats' opens a cursor and goes through each value of the database until
> we find a value with the same 'appId' and 'serviceType' than the updated
> record that should be stored. When the database is small there is no
> problem, but for a large database there is a considerable lag. Using
> Alexander's db file in hamachi it takes one minute.
> 
> From my point of view, we can add an index to indexedDB to avoid going
> across the whole records.
> 
> Are you agree?
> 
> [1]
> https://mxr.mozilla.org/mozilla-central/source/dom/network/src/
> NetworkStatsDB.jsm#361

Sure! We definitely need to solve it!
Thanks Albert ;)

Comment 17

[Gene Lian (I already quit Mozilla)]

Yeap! Sounds good to me.

Comment 18

[Albert [:albert]]

Attachment: bug-1034490-fix

Don't need to add a new index, used current keypath with keyrange instead of search using cursor.continue().

keyPath: ["appId", "serviceType", "network", "timestamp"]

Comment 19

[John Shih]

Comment on attachment 8454266 [details] [diff] [review]
bug-1034490-fix

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

Looks good to me! Just make sure pass all the test cases!

Comment 20

[Albert [:albert]]

Try: https://tbpl.mozilla.org/?tree=Try&rev=ea24c59513bb

Comment 21

[Gene Lian (I already quit Mozilla)]

Comment on attachment 8454266 [details] [diff] [review]
bug-1034490-fix

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

Nice! r=gene

Comment 22

[:gerard-majax]

Alert, do you need that I test this ?

Comment 23

[Albert [:albert]]

(In reply to Alexandre LISSY :gerard-majax from comment #22)
> Alert, do you need that I test this ?

I tested in my own, but it would be great if you can also test it.

Thank you!

Comment 24

[:gerard-majax]

I just tested, now the Usage app take 1-2 secs to display the plot :)

Comment 25

[Gene Lian (I already quit Mozilla)]

https://hg.mozilla.org/integration/b2g-inbound/rev/29a15c4d6324

Comment 26

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/29a15c4d6324

Comment 27

[Ryan VanderMeulen [:RyanVM]]

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

Comment 28

[Sue]

Attachment: verify_video.MP4

This issue has been verified successfully on Flame v2.0
See attachment: verify_video.MP4
Reproducing rate: 0/5
Flame 2.0 versions:
Gaia-Rev        856863962362030174bae4e03d59c3ebbc182473
Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g32_v2_0/rev/e40fe21e37f1
Build-ID        20141207000206
Version         32.0
Device-Name     flame
FW-Release      4.4.2
FW-Incremental  eng.cltbld.20141207.034341
FW-Date         Sun Dec  7 03:43:52 EST 2014
Bootloader      L1TC00011880

Comment 29

[Sue]

Attachment: Flame 2.1.MP4

Hi Mike,
Could you help with it, thanks.
This issue has been verified unsuccessfully on Flame v2.1
STR:
1. Launch Usage.
2. Use mobile data and Wi-Fi to view some website or play a online video.
3. Back to Usage check the uasge.
**The usage of mobile data and Wi-Fi have no change.
Found time: 16:55
See attachment: Flame 2.1.MP4 and logcat_1655.txt
Reproducing rate: 0/5
Flame 2.1 versions:
Gaia-Rev        38e17b0219cbc50a4ad6f51101898f89e513a552
Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g34_v2_1/rev/8b92c4b8f59a
Build-ID        20141205001201
Version         34.0
Device-Name     flame
FW-Release      4.4.2
FW-Incremental  eng.cltbld.20141205.035305
FW-Date         Fri Dec  5 03:53:16 EST 2014
Bootloader      L1TC00011880

Comment 30

[Sue]

Attachment: logcat of flame 2.1

Hi Mike,
Could you help with it, thanks.

Comment 31

[Mike Lien[:mlien]]

I cannot open comment 29's attached video successfully, it shows file is broken.
Verified again with v2.1, it actually refresh data/Wi-Fi usage within 2 seconds after switching to Usage app

Gaia-Rev        38e17b0219cbc50a4ad6f51101898f89e513a552
Gecko-Rev       https://hg.mozilla.org/releases/mozilla-b2g34_v2_1/rev/8b92c4b8f59a
Build-ID        20141205001201
Version         34.0
Device-Name     flame
FW-Release      4.4.2
FW-Incremental  eng.cltbld.20141126.193631
FW-Date         Wed Nov 26 19:36:42 EST 2014
Bootloader      L1TC10011880