Contacts delete operation takes 4 times longer in 2.2 than in 2.1 when you delete 500 contacts

RESOLVED DUPLICATE of bug 1114520

Status

()

Core
DOM: Contacts
--
major
RESOLVED DUPLICATE of bug 1114520
4 years ago
4 years ago

People

(Reporter: Shiwei Zhang, Assigned: reuben)

Tracking

({perf, regression})

37 Branch
ARM
Gonk (Firefox OS)
perf, regression
Points:
---

Firefox Tracking Flags

(blocking-b2g:2.2+, b2g-v2.0 unaffected, b2g-v2.1 unaffected, b2g-v2.2 affected)

Details

(Whiteboard: [sprd388917][dp3])

Attachments

(3 attachments)

(Reporter)

Description

4 years ago
*** Build Information
Gaia-Rev        73be51f998031f06db0cd660c0e388fa621c9f4c
Gecko-Rev       30de9395e2c3e4c3d640bc6c70ddbc1a8c8cf88f
Device-Name     dolphin

*** Description
Contacts delete operation spend a long time.

*** Steps to Reproduce
1.Fill 500 contacts in App.
2.Contacts -> Settings -> Delete Contacts -> Select all. 
3.Delete selected contacts.

*** Expected Results
The performance of contacts delete operation in Firefox OS is the same as Android.

*** Actual Results
The performance of contacts delete operation in Firefox OS is worse than Android.

The average time
7715ea-FFOS :18.486s
Flame-FFOS :45.039s
7715ea-Android: 10.117s
(Reporter)

Comment 1

4 years ago
I made some contacts deleting experiments. It was found that the request of mozContacts.remove(contact)  tooks about 100ms seconds to call onsuccess back, sometimes the waiting time is more than 600ms.

It may be necessary to do some optimization work with this web API.
QA wanted to measure the performance with 2.0, 2.1 and 2.2 on the Flame. It's possible to use the medium reference workload[1] to rapidly get the 500 contacts.

[1] https://developer.mozilla.org/en-US/Firefox_OS/Developing_Gaia/make_options_reference#Reference_Workloads
Keywords: perf, qawanted
Looks to me like a api issue, will change component check in comment 2
QA Contact: bzumwalt
Issue DOES occur on Flame 2.0, 2.1, and 2.2

Average times to delete 500 entries from Contacts app:
2.0: 91 seconds
2.1: 68 seconds
2.2: 226 seconds

Tested each branch three times. Contacts were generated using Make Reference Workload (Medium)

Device: Flame 2.0 (319mb)(Kitkat Base)(Shallow Flash)
BuildID: 20150105000200
Gaia: 3c9bb36d9ade1a0acd5e1d6cbb5057be7f5ad484
Gecko: 93f5c85a1d31
Version: 32.0 (2.0)
Firmware: V188-1
User Agent: Mozilla/5.0 (Mobile; rv:32.0) Gecko/32.0 Firefox/32.0

Device: Flame 2.1 (319mb)(Kitkat Base)(Shallow Flash)
BuildID: 20150105001204
Gaia: 73be51f998031f06db0cd660c0e388fa621c9f4c
Gecko: 05dd053f1d90
Version: 34.0 (2.1)
Firmware: V188-1
User Agent: Mozilla/5.0 (Mobile; rv:34.0) Gecko/34.0 Firefox/34.0

Device: Flame 2.2 Master (319mb)(Kitkat Base)(Shallow Flash)
BuildID: 20150105010205
Gaia: c2bf20d23851d5fda9f8f0ef0267db5f49152376
Gecko: 636498d041b5
Version: 37.0a1 (2.2 Master)
Firmware: V188-1
User Agent: Mozilla/5.0 (Mobile; rv:37.0) Gecko/37.0 Firefox/37.0
QA Whiteboard: [QAnalyst-Triage?]
status-b2g-v2.0: --- → affected
status-b2g-v2.1: --- → affected
status-b2g-v2.2: --- → affected
Flags: needinfo?(ktucker)
Keywords: qawanted
QA Whiteboard: [QAnalyst-Triage?] → [QAnalyst-Triage+]
Flags: needinfo?(ktucker)
Waw the average time on 2.2 is really high. Do you still have the raw numbers for each branch, Brogan?
Flags: needinfo?(bzumwalt)
The difference between tests weren't that great. For 2.0 and 2.1 I think the split times never surpassed around 10 seconds.

The raw results for 2.2, in three new tests using same testing method as used in comment 4:

Flame 2.2 Deletion time for 500 contacts:  240 seconds, 228 seconds, 225 seconds (average time 231 seconds)
QA Whiteboard: [QAnalyst-Triage+] → [QAnalyst-Triage?]
Flags: needinfo?(bzumwalt) → needinfo?(ktucker)
I experienced this myself and I can really see the difference between 2.1 and 2.2.

[Blocking Requested - why for this release]: The time to delete 500 contacts has been increased by 4 between 2.1 and 2.2.
blocking-b2g: --- → 2.2?
QA Whiteboard: [QAnalyst-Triage?] → [QAnalyst-Triage+]
Flags: needinfo?(ktucker)
Triage: Regression
blocking-b2g: 2.2? → 2.2+

Updated

4 years ago
Whiteboard: [sprd388917] → [sprd388917][dp3]
I deleted 500 contacts on last central[1] => it took 244 seconds.
Then, I flashed this 2.1 gaia revision[2] on top of central => it took about the same time: 253 seconds. 

It's a gecko issue then.

Another note, it seems that the less you have remaining contacts to delete, the faster it is. At the beginning of the 500 batch, it takes like 4 or 5 seconds to delete a single contact. At the end, you're able to delete the last 10 in less than a second.
It looks like we don't have a linear time complexity anymore. 

I renamed the bug to reflect more the regression here.

[1] Gaia-Rev        9946a490a9264b42e65385d703b28fa055ab2d42
Gecko-Rev       https://hg.mozilla.org/mozilla-central/rev/67257a3edeb5
Build-ID        20150113160228
Version         38.0a1
Device-Name     flame
FW-Release      4.4.2
FW-Incremental  eng.jlorenzo.20141211.144125
FW-Date         Thu Dec 11 14:41:42 CET 2014
Bootloader      L1TC000118D0

[2] Gaia-Rev        6957ac8a322234ec99c8abb7cc18dc6a2e0176db
status-b2g-v2.0: affected → unaffected
status-b2g-v2.1: affected → unaffected
Component: Gaia::Contacts → DOM: Contacts
Product: Firefox OS → Core
Summary: [Contacts][dolphin][FFOS7715 v2.1] [performance] Contacts delete operation spend a longer time → Contacts delete operation takes 4 times longer in 2.2 than in 2.1
Version: unspecified → 37 Branch
Summary: Contacts delete operation takes 4 times longer in 2.2 than in 2.1 → Contacts delete operation takes 4 times longer in 2.2 than in 2.1 when you delete 500 contacts

Comment 10

4 years ago
Created attachment 8549501 [details]
bug388917_sprd_gaia_gecko.tar.gz

Dear all,
  Could you help me to review this patch(bug388917_sprd_gaia_gecko.tar.gz). After modification,I test that delete 500 contacts spend 38s.
  In this patch, I add removeContacts API in file ContactManager.js. And I modified file contacts_remover.js which belongs to gaia. Gaia send 20 contacts per time to gecko to realize bulk delete. So it just need cycle 25 times to complete delete 500 contacts.

  Additional,after I modified file contacts_remover.js, I use command "git diff", I find many "^M" at the end of every line. The patch of this file couldn't be applied success, so I can't push my changes to my branch. 

  Thanks a lot.
Having a bulk capability could be actually nice, but I think we really need to know what regressed.

Johan, do you think it's possible to have a window with this?
Keywords: regression, regressionwindow-wanted
From the log of changes in dom/contacts, it could be bug 1072773. Maybe staying in a single transaction made things slower, and in that case maybe the only solution is a bulk capability.
(In reply to Julien Wajsberg [:julienw] from comment #11)
As it takes a very long time to delete the first 10 contacts, we don't need to wait until the whole deletion is complete. Hence, a regression window sounds doable.
Gecko Regression Window:

Gecko B2G-Inbound last working build:
Device: Flame 2.2
BuildID: 20141022125314
Gaia: 3536e6038212f9c5dc08a763ed6555494f24e38b
Gecko: eb4d4fbac027
Version: 36.0a1 (2.2)
Firmware: V18D-1
User Agent: Mozilla/5.0 (Mobile; rv:36.0) Gecko/36.0 Firefox/36.0

Gecko B2G-Inbount first broken build:
Device:  2.2
BuildID: 20141022151219
Gaia: 3536e6038212f9c5dc08a763ed6555494f24e38b
Gecko: badc56be9f64
Version: 36.0a1 (2.2)
Firmware: V18D-1
User Agent: Mozilla/5.0 (Mobile; rv:36.0) Gecko/36.0 Firefox/36.0

Working Gecko with Broken Gaia issue does NOT reproduce
Gaia: 3536e6038212f9c5dc08a763ed6555494f24e38b
Gecko: eb4d4fbac027

Working Gaia with Broken Gecko issue DOES reproduce:
Gaia: 3536e6038212f9c5dc08a763ed6555494f24e38b
Gecko: badc56be9f64

Gecko B2G-Inbound Pushlog: 
http://hg.mozilla.org/integration/b2g-inbound/pushloghtml?fromchange=eb4d4fbac027&tochange=badc56be9f64

Issue appears to have been caused by bug 1072773
QA Whiteboard: [QAnalyst-Triage+] → [QAnalyst-Triage?]
Flags: needinfo?(ktucker)
Keywords: regressionwindow-wanted
Kyle, can you get you look at this please? Looks like the fix for bug 1072773 may have caused this issue.
QA Whiteboard: [QAnalyst-Triage?] → [QAnalyst-Triage+]
Flags: needinfo?(ktucker) → needinfo?(khuey)
Unless you tested with the dom.indexedDB.fullSynchronous preference set, this was caused by Reuben's changes, not mine.
Flags: needinfo?(khuey) → needinfo?(reuben.bmo)
Hey Francisco, when we delete contact in the Contacts app, are we deleting them one by one, waiting for the one success before deleting the next one?

Maybe Reuben's patch made deleting one contact slower because the transaction lasts longer, but maybe we could have 3 or 4 "delete" operations together?

Or how do you feel about introducing a bulk deleting operation?
Flags: needinfo?(francisco)
Francisco told me last week that we delete the contacts one by one even if all the contacts are selected.
Flags: needinfo?(francisco)
(Assignee)

Comment 19

4 years ago
Calling clear() instead of lots of remove() when all contacts are selected is a good optimization, but the regression should be fixed anyway. Looking.
Flags: needinfo?(reuben.bmo)
(Assignee)

Comment 20

4 years ago
Created attachment 8551556 [details] [diff] [review]
Correctly remove contact IDs from the getall cache on remove()

Wow, I don't even know what to say…

We were iterating over the entire contact store on every one of those remove() calls, because of this insane part of my patch from bug 1072773.
Assignee: nobody → reuben.bmo
Attachment #8551556 - Flags: review?(anygregor)
(Assignee)

Comment 21

4 years ago
Created attachment 8551557 [details] [diff] [review]
Add and remove 500 contacts

For archival.
Blocks: 1072773
Reuben, this very same patch has already been done in bug 1114520. And as you'll see from I comment I left there, it's not correct, because we then reuse the same transaction in "removeContact", so if we don't start a transaction for both stores, we won't be able to actually remove the contact.

Ferjm just provided a follow-up to the patch in that bug too. Maybe you'd want to have a look there to see if this fix this bug too.
Flags: needinfo?(reuben.bmo)
(Assignee)

Comment 23

4 years ago
(In reply to Julien Wajsberg [:julienw] from comment #22)
> we then
> reuse the same transaction in "removeContact", so if we don't start a
> transaction for both stores, we won't be able to actually remove the contact.

After bug 1072773, removeContact explicitly grabs the main store before doing anything, so it should work.

> Ferjm just provided a follow-up to the patch in that bug too. Maybe you'd
> want to have a look there to see if this fix this bug too.

I'll look at that bug.
Flags: needinfo?(reuben.bmo)
(Assignee)

Comment 24

4 years ago
Comment on attachment 8551556 [details] [diff] [review]
Correctly remove contact IDs from the getall cache on remove()

The patch in bug 1114520 fixes this, and it has a test.
Attachment #8551556 - Flags: review?(anygregor)
Should we dupe, then ? :)

Comment 26

4 years ago
I'd like to delete this as a duplicate. May I?
Flags: needinfo?(reuben.bmo)
(Assignee)

Comment 27

4 years ago
Yep, I should've already done that. Thanks for the reminder.
Status: NEW → RESOLVED
Last Resolved: 4 years ago
Flags: needinfo?(reuben.bmo)
Resolution: --- → DUPLICATE
Duplicate of bug: 1114520
You need to log in before you can comment on or make changes to this bug.