Closed Bug 860612 Opened 12 years ago Closed 11 years ago

[Call Log] When deleting 500 call logs, dialer app takes too long time to delete

Categories

(Firefox OS Graveyard :: Gaia::Dialer, defect, P1)

Product:
Firefox OS Graveyard
Component:
Gaia::Dialer
Platform:
ARM
Gonk (Firefox OS)
Type:
defect

Tracking

(blocking-b2g:leo+, b2g18 fixed)

Status:
RESOLVED FIXED
Milestone:
1.1 QE1 (5may)
Project Flags:
blocking-b2g leo+
Tracking Flags:
Tracking Status
b2g18 --- fixed

People

(Reporter: leo.bugzilla.gaia, Assigned: rexboy)

References

Details

(Whiteboard: [QE1], [TD-11594] )

1. Title : When deleting 500 call logs, dialer app takes too long time to delete 2. Precondition : Restore 500 call logs 3. Tester's Action : Run dialer app >> Delete all logs 4. Detailed Symptom : Dialer app takes 45.8 seconds(3 times average), however it should be under 1.5 seconds according to leo device spec 5. Expected : Dialer app takes under 1.5 seconds 6. Reproducibility: Y 1) Frequency Rate : 100% 7. Gaia revision :
blocking-b2g: --- → leo?
leo+ for now assuming this is a regression, and qawanted to find out if v1.0.1 is affected. If yes, please mark as blocking-b2g:tef?
blocking-b2g: leo? → leo+
Keywords: qawanted
Here which is the requirement? How many call logs must be supported by the app?
Whiteboard: [QE1]
Whiteboard: [QE1] → [QE1], [TD-11594]
Target Milestone: --- → Leo QE1 (5may)
QA Contact: carlos.martinez
Not sure if it's by design.. I can take a look.
Assignee: nobody → rexboy
Seems it's related to 848027. There are already some improvement plan on performance in progress. Still investigating.
oops. I mean bug 848027.
Not able to repro in v1.0.1 as script to load calls in the call log is not working in v1.0.1 due to db incompatibility problems. Trying to investigate a bit more.
As far as I know, IndexedDB can only delete items one-by-one, or by a range deletion. This is why the deletion being slow under this case because we delete logs by a checklist, so it can only delete items one-by-one referring to the list, which in turn needs 500 queries to indexedDB. If we want to treat "clear all" as a especially commonly-use feature that needs to be speed-up, setting a special case to perform "clearAll" on indexedDB when user selected all items may help. This doesn't improve cases that user wants to leave a few call logs though. :ferjm do you have any suggestions on this?
Flags: needinfo?(ferjmoreno)
(In reply to KM Lee [:rexboy] (Away 4/4~4/14) from comment #7) > > If we want to treat "clear all" as a especially commonly-use feature that > needs to be speed-up, setting a special case to perform "clearAll" on > indexedDB when user selected all items may help. This doesn't improve cases > that user wants to leave a few call logs though. We already added the 'deleteAll' function [1] that should be fast for this case. It should be used in Bug 848027. [1] https://github.com/mozilla-b2g/gaia/blob/master/apps/communications/dialer/js/recents_db.js#L360
Flags: needinfo?(ferjmoreno)
Thank you :ferjm. Let's set it as blocking.
Depends on: 848027
Priority: -- → P1
Based on KM's feedback, once bug 848027 is fixed, it might require another 2-3 days(at most) to fix this one.
Fernando - QA is stuck is having a good method to test this on v1.01. Do you know of an easy way to generate a 500 call log on 1.01 to test this?
Flags: needinfo?(ferjmoreno)
You can use the reference workloads https://github.com/mozilla-b2g/gaia/blob/master/Makefile#L307
Flags: needinfo?(ferjmoreno)
It seems that the reference workloads are not available in 1.0.1. Jon, would it be possible to uplift the required patches that contains the reference workloads to 1.0.1?
Flags: needinfo?(jhylands)
Its on the list of things to do. For now, you can run reference workloads from a m-c repo against a 1.0.1 phone. It checks for the differences and deals with it automatically.
Flags: needinfo?(jhylands)
Note that in order to do this, you need a fairly recent m-c repo on your desktop - I only fixed this issue (pushing to v1-train phones) in the last week or so.
Thanks Jon, we will try with a recent repo.
I´ve tried with latest master and yesterday´s v1.0.1 build and still not working. Contacts are well loaded, but call log is empty.
Carlos - Can we hook up via Vidyo or skype so we can resolve this?
Carlos - I just flashed my unagi with current v1-train, and ran the following: 2046 >APP="communications/dialer" make reference-workload-x-heavy cat: *apps/communications/dialer/manifest.webapp: No such file or directory cat: *apps/communications/dialer/manifest.webapp: No such file or directory test_media/reference-workload/makeReferenceWorkload.sh x-heavy Waiting for device to be connected... Device connected Populate Databases - x-heavy Workload idb directory not present 273 KB/s (24013 bytes in 0.085s) 2366 KB/s (655360 bytes in 0.270s) Summary: Dialer History: 500 Done --- The specific line you should look for is: "idb directory not present" If you don't see that, then it is pushing to the wrong place. Note that with 500 numbers, it takes the dialer history many seconds to show the list of numbers. I timed it, and it took 18 seconds for me.
That´s what I´m seeing for v1.0.1: root@carlos-VirtualBox:/home/carlos/gaia# APP="communications/dialer" make reference-workload-medium cat: *apps/communications/dialer/manifest.webapp: No existe el archivo o el directorio cat: *apps/communications/dialer/manifest.webapp: No existe el archivo o el directorio test_media/reference-workload/makeReferenceWorkload.sh medium Waiting for device to be connected... Device connected Populate Databases - medium Workload idb directory not present 139 KB/s (13752 bytes in 0.096s) 406 KB/s (524288 bytes in 1.260s) Summary: Dialer History: 100 Done
Carlos, do you see any JavaScript errors show up in logcat when you run the dialer app, and choose the history button?
http://pastebin.mozilla.org/2349111 there you have the logcat, the only JS error I see is: E/GeckoConsole( 604): [JavaScript Error: "NS_NOINTERFACE: Component does not have requested interface arg 0 [nsIRilContext.icc]" {file: "file:///system/b2g/distribution/bundles/libqc_b2g_ril/QCContentHelper.js" line: 29}]
In my test a few days ago, I can get call logs only when executing workload-x-heavy set. Not sure about the reason.
Carlos - if you want me to investigate this further, you'll have to get in touch via IRC or Skype... We'll have to do some remote debugging, and its too awkward to do here in bug comments. Please email me at jhylands@mozilla.com for contact info.
To unblock the QA request (even though we should try to figure out the root cause of the problem we're hitting here), can someone who is able to get the heavy workload working on v1.01 able to just quickly test this to see if this reproduces on v1.01?
Carlos - Did you get the chance to follow up with Jon here?
Flags: needinfo?(carlos.martinez)
With make reference-workload-light, I was able to reproduce this on a 1.1 leo device, with 50 call logs. With 50 call logs alone, it was already taking about 4.5 seconds. So if you multiple that by 500 contacts, it's not a surprise that we're hitting 45 secs. I'll try right now on a 1.0.1 inari device, as what the original QAwanted ask was. Anyway, what's the requirement for contact importing performance? the original bug says "5. Expected : Dialer app takes under 1.5 seconds", but i don't know where that requirement is coming from. Can someone clarify if this is a certification blocker?
Flags: needinfo?(carlos.martinez)
Daniel - Can address comment 27 to check if this is a certification blocker for 1.01?
Flags: needinfo?(dcoloma)
(In reply to Jon Hylands [:jhylands] from comment #24) > Carlos - if you want me to investigate this further, you'll have to get in > touch via IRC or Skype... We'll have to do some remote debugging, and its > too awkward to do here in bug comments. Please email me at > jhylands@mozilla.com for contact info. Hi Jon, I also tried to run make reference-workload-x-heavy on the Inari v1.0.1 device, and was hitting the idb directory not present issue. Heres' my logcat and cmd line output. any thoughts? Cmd line output: *********** Tonys:gaia tchung$ make reference-workload-x-heavy test_media/reference-workload/makeReferenceWorkload.sh x-heavy Waiting for device to be connected... Device connected Populate Databases - x-heavy Workload idb directory not present 353 KB/s (355856 bytes in 0.982s) mid3v2 required to load music - install with |sudo apt-get install python-mutagen| No music loaded 1988 KB/s (123243 bytes in 0.060s) failed to copy '/Users/tchung/Desktop/BuildB2G/B2G/gaia/test_media/reference-workload/contactsDb-2000.sqlite' to '/data/local/indexedDB/chrome/3406066227csotncta.sqlite': Permission denied failed to copy '/Users/tchung/Desktop/BuildB2G/B2G/gaia/test_media/reference-workload/smsDb-2000.sqlite' to '/data/local/indexedDB/chrome/226660312ssm.sqlite': Permission denied remote object '/data/local/webapps/webapps.json' does not exist Traceback (most recent call last): File "/Users/tchung/Desktop/BuildB2G/B2G/gaia/test_media/reference-workload/readJSON.py", line 10, in <module> json_data=open(sys.argv[1]) IOError: [Errno 2] No such file or directory: '/Users/tchung/Desktop/BuildB2G/B2G/gaia/test_media/reference-workload/webapps.json' Unable to determine communications application ID - skipping dialer history... Summary: Gallery: 250 Music: 250 Videos: 50 Contacts: 2000 Sms Messages: 2000 Dialer History: skipped Done Tonys:gaia tchung$ Logcat: ***** 05-02 20:30:41.379: I/GonkSwitch(150): ++lg_fw_diagcmd++ GetSubSystem 05-02 20:30:41.379: I/GonkSwitch(150): Gonk Switch don't notify : SWITCH_DEVICE_UNKNOWN 05-02 20:31:15.429: I/IdleService(482): Get idle time: time since reset 300010 msec 05-02 20:31:15.429: I/IdleService(482): Idle timer callback: current idle time 300010 msec 05-02 20:31:15.439: I/IdleService(482): next timeout 4294966994986 msec from now 05-02 20:31:15.439: I/IdleService(482): SetTimerExpiryIfBefore: next timeout 4294966994985 msec from now 05-02 20:31:15.439: I/IdleService(482): reset timer expiry to 4294966994993 msec from now 05-02 20:31:15.439: I/IdleService(482): Idle timer callback: tell observer 445d2800 user is idle 05-02 20:31:15.439: I/IdleService(482): Notifying idle-daily observers 05-02 20:31:15.449: I/IdleService(482): Remove idle observer 445d2800 (300 seconds) 05-02 20:31:15.449: I/IdleService(482): Storing last idle time as 1367519475
Jon, ignore the last comment. i reran the script, and it's showing this instead. test_media/reference-workload/makeReferenceWorkload.sh x-heavy Waiting for device to be connected... Device connected Populate Databases - x-heavy Workload idb directory not present 1871 KB/s (355856 bytes in 0.185s) mid3v2 required to load music - install with |sudo apt-get install python-mutagen| No music loaded 2644 KB/s (123243 bytes in 0.045s) 2184 KB/s (10190848 bytes in 4.555s) 2715 KB/s (5832704 bytes in 2.097s) 1383 KB/s (12472 bytes in 0.008s) 1856 KB/s (655360 bytes in 0.344s) Summary: Gallery: 250 Music: 250 Videos: 50 Contacts: 2000 Sms Messages: 2000 Dialer History: 500 Done So no permissions issue, but still "idb directory not present". any clues?
I do not think we should block on this for v1.0.1; I am really afraid of regressions in this case. Alberto, what do you think?
Flags: needinfo?(dcoloma) → needinfo?(alberto.pastor)
did more testing on v1.0.1 build for Inari. turns out even doing a "make reference-workload-light" is not showing any call log data on the dialer UI. (ie. only logs 50 dialer history) talked to jon, and he gave me another dialer-50 script to push to device. same result, no call logs shown on device. but data/local shows correctly: -rw-rw-rw- root root 59392 2013-05-02 15:42 2584670174dsitanleecreR.sqlite Environment: Device: Inari Gecko http://hg.mozilla.org/releases/mozilla-b2g18_v1_0_1/rev/5c1d67e0c242 Gaia 11477c127ae9be5051e4cfbcbf3da1d4150f9967 BuildID 20130502070201 Version 18.0 i've yet to try on another device with a b2g18_101 build. Leaving qawanted on the bug until we can get the test environment up for 1.0.1 and actually test the bug.
If this is a non-blocker for 1.01, then there's no reason to do QA testing to see if this reproduces on 1.01. I'll wait for Alberto's response here, but if he confirms that we should not block on this for 1.01 even if this reproduces, then let's pull the qawanted keyword here.
Status update: This bug is still blocked by bug 847406. Depending on the result of bug 847406, this bug can be automatically fixed if it's fast enough to perform delete all. If it's not, we would try to modify it to do 'delete all' on database in case all logs are selected.
(In reply to Daniel Coloma:dcoloma from comment #31) > I do not think we should block on this for v1.0.1; I am really afraid of > regressions in this case. Alberto, what do you think? The current implementation doesn't scale at all and we don't limit the number of items in the log. This is a terrible combination and I am really afraid that this bug will hit every user sooner or later. I hope this becomes a dup of bug 847406.
QA has made a worthy effort at this, but given that we're hitting too many roadblocks getting the heavy workload script running on 1.01 and the above discussion seems to imply that this might be present on 1.01, I'm inclined to say let's just make the final decision if we want this for 1.01 or not.
blocking-b2g: leo+ → tef?
Keywords: qawanted
QA Contact: carlos.martinez
Right now, the dialer reference workload databases appear to be incompatible with 1.0.1. I'm going to check into this today, and will open a bug on it if that is the case - the dialer migration scripts should handle upgrade of a version 1 database automatically.
John got me a working sqlite file of about 50 logs today against the inari 1.0.1 nightly. i populated the call log, then clocked the delete all of the 50 logs. after testing 3 times, the average was right around 1.5 seconds. Unfortunately, john's dialer-500 script doesnt load 500 contacts, so i still can't test that scenario yet on 1.0.1. but at least i can confirm deleting 50 logs is right around 1.5 secs. I'll try this again if i can get the dialer-500 script to work.
It's a pity as I would really love to fix this, but this is not the right moment to do the significant amount of changes required to fix it for 1.0.1.
Whiteboard: [QE1], [TD-11594] → [QE1], [TD-11594] [tef-triage]
Given comment 39, to whoever triages this, set it back to leo+.
Just to clarify - in terms of reference workload, I now have various sized dialer history databases available that are compatible with 1.0.1, and tchung has access to them, so having a large call database is no longer an impediment to resolving this bug.
Putting back to leo+ in that case. Jon, the ability to use the database in testing isn't the barrier to resolving, this requires too much late-landing churn and is too high risk for v1.0.1 at this stage.
blocking-b2g: tef? → leo+
Whiteboard: [QE1], [TD-11594] [tef-triage] → [QE1], [TD-11594]
I think Bug 847406 + Bug 847409 will solve this bug.
Flags: needinfo?(alberto.pastor)
(In reply to Daniel Coloma:dcoloma from comment #39) > It's a pity as I would really love to fix this, but this is not the right > moment to do the significant amount of changes required to fix it for 1.0.1. Could we limit the number of log entries to a sane number? Maybe just store the last 30 calls.
Thanks to Alberto's great work in Bug 847406, the deleteAll() feature has already implemented by his patch. Deleting 614 entries (generated by reference-workload-x-heavy) on my Unagi spent about just 4 seconds, so I think we can mark this bug as fixed directly.
Status: NEW → RESOLVED
Closed: 11 years ago
Resolution: --- → FIXED
Flags: in-moztrap?
Added test case in MozTrap: https://moztrap.mozilla.org/manage/case/8506/
Flags: in-moztrap? → in-moztrap+
You need to log in before you can comment on or make changes to this bug.