Last Comment Bug 426991 - Form submission extremely slow on large forms (with form history turned on)
: Form submission extremely slow on large forms (with form history turned on)
Status: RESOLVED FIXED
: perf, verified1.9.0.9
Product: Toolkit
Classification: Components
Component: Form Manager (show other bugs)
: Trunk
: All All
: -- normal with 2 votes (vote)
: mozilla1.9.1b2
Assigned To: Justin Dolske [:Dolske]
:
: Matthew N. [:MattN] (PM me if requests are blocking you)
Mentors:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2008-04-04 03:10 PDT by Karel Kolman
Modified: 2009-03-19 16:55 PDT (History)
6 users (show)
See Also:
Crash Signature:
(edit)
QA Whiteboard:
Iteration: ---
Points: ---
Has Regression Range: ---
Has STR: ---


Attachments
A form with 100+ inputs. (29.75 KB, text/html)
2008-04-04 03:14 PDT, Karel Kolman
no flags Details
Patch v.1 (2.24 KB, patch)
2008-10-06 17:25 PDT, Justin Dolske [:Dolske]
sdwilsh: review+
Details | Diff | Splinter Review
Patch v.2 (2.32 KB, patch)
2008-10-07 16:25 PDT, Justin Dolske [:Dolske]
gavin.sharp: review+
Details | Diff | Splinter Review

Description Karel Kolman 2008-04-04 03:10:42 PDT
User-Agent:       Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9b5) Gecko/2008032620 Firefox/3.0b5
Build Identifier: Mozilla/5.0 (Windows; U; Windows NT 5.1; en-US; rv:1.9b5) Gecko/2008032620 Firefox/3.0b5

When submitting a form with many inputs, it takes a long time before the entered values are crunched by form history manager and form submission actually happens.
I have a 120+ inputs form, it takes 10 second before request is sent to the form action target url. I have a not-so-fast Sempron 2400+ system with an old hard disk. I hear heavy disk activity after clicking the Submit button.

Resubmitting the same form is fast. Clearing the form history (through Clear private data) and resubmitting the form takes a long time again.

Reproducible: Always

Steps to Reproduce:
1. Open a page with a form with many inputs in the browser.
2. Clear private data history.
3. Submit the form.
4. Submit the form again.
Actual Results:  
Step 3. takes way too long to finish.
Step 4. finishes quickly.

Expected Results:  
A previously not submitted form with many inputs will take only slightly more time to submit than subsequent submissions of the same form.
Comment 1 Karel Kolman 2008-04-04 03:14:23 PDT
Created attachment 313567 [details]
A form with 100+ inputs.

A form with 100+ inputs (post action to the same file).
It takes 10+ seconds on my system to submit.
The formhistory.sqlite db has 9216 bytes when submitting in a clean profile.
Comment 2 Karel Kolman 2008-04-04 03:33:19 PDT
Created a profile on the same system but located on a much faster sata disk, the initial form submission delay is a bit noticeable but generally much shorter (around 1 sec). 
Comment 3 KenLai 2008-06-30 07:53:59 PDT
I met the same problem. 
web form has about 1000 input fields

environment                           resullt
firefox 2.0.0.14 + win xp             ok(1 sec)
firefox 3.0 + winxp                   slow(above 20 secs)
firefox(v2 or v3)+ win2000            very slow(above 30secs). 
Comment 4 Justin Dolske [:Dolske] 2008-09-06 15:00:14 PDT
Yeah, yikes, something crazy is going on here. Submitting the testcase from comment 1 results in 1748 disk operations for formhistory. :-O A small segment from a typical rwsnoop run on my OS X box looks like:

# rwsnoop -vp 44159
TIMESTR                UID    PID CMD          D   BYTES FILE
...
Sep  6 14:51:45   501  44159 firefox-bin  W      24 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W       1 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W       4 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W    1024 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W       4 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W       4 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W    1024 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W       4 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W       4 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W    1024 formhistory.sqlite
Sep  6 14:51:45   501  44159 firefox-bin  W    1024 formhistory.sqlite
Sep  6 14:51:45   501  44159 firefox-bin  W       4 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W    1024 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W       4 formhistory.sqlite-journal
Sep  6 14:51:45   501  44159 firefox-bin  W       4 formhistory.sqlite-journal
...
Comment 5 Justin Dolske [:Dolske] 2008-09-06 15:05:09 PDT
Looks like we create a transaction and execute a statement for *each* form field that's saved. I'm going to go out on a limb and guess that's not the most efficient way to be doing things. :-)
Comment 6 Shawn Wilsher :sdwilsh 2008-09-06 16:59:51 PDT
(In reply to comment #5)
> Looks like we create a transaction and execute a statement for *each* form
> field that's saved. I'm going to go out on a limb and guess that's not the most
> efficient way to be doing things. :-)
No, and that'd be why you hit the perf issue!

I'm not sure where this code lives, but this sounds like a prime candidate to use the async storage API too!
Comment 7 Justin Dolske [:Dolske] 2008-10-06 17:25:54 PDT
Created attachment 342003 [details] [diff] [review]
Patch v.1

Fixes the problem by removing the per-entry transaction, and instead using a per-form transaction.

I benchmarked this by measuring the time it takes to execute the for-loop in Notify() [which this patch wraps in a transaction]. Repeated 5 times, deleting formhistory.sqlite in between runs (we short-circuit when the saved value already exists).

In the current code, submitting the attached testcase was measured at 224ms. With this patch, it now takes 8ms. 28x faster, woo! :-)

Looking at the file IO with DTrace, I see a handful of tiny writes to formhistory-sqlite-journal, followed by 8 1K writes to formhistory.sqlite, followed by a few more writes to formhistory-sqlite-journal. Much better than the flood I saw in comment 4.
Comment 8 Justin Dolske [:Dolske] 2008-10-06 17:28:08 PDT
Oh, meant to also note: I also measured the perf with removing the per-entry transaction (but not adding the per-form transaction), and didn't see a significant change in the numbers.
Comment 9 Shawn Wilsher :sdwilsh 2008-10-06 17:28:51 PDT
(In reply to comment #8)
> Oh, meant to also note: I also measured the perf with removing the per-entry
> transaction (but not adding the per-form transaction), and didn't see a
> significant change in the numbers.
What is more interesting in both cases is the number of fsyncs.
Comment 10 Shawn Wilsher :sdwilsh 2008-10-07 10:26:58 PDT
Comment on attachment 342003 [details] [diff] [review]
Patch v.1

>+  transaction.Commit();
> 
>   return NS_OK;
please return the value from transaction.Commit() - it's possible it could fail.

r=sdwilsh with that fixed.
Comment 11 Justin Dolske [:Dolske] 2008-10-07 16:25:22 PDT
Created attachment 342161 [details] [diff] [review]
Patch v.2
Comment 12 Justin Dolske [:Dolske] 2009-03-17 15:01:44 PDT
This fix was included as part of bug 483096.
Comment 13 Justin Dolske [:Dolske] 2009-03-17 15:03:14 PDT
(On 1.9.0.8, that is.)
Comment 14 Al Billings [:abillings] 2009-03-19 16:55:45 PDT
Verified through bug 483096 for 1.9.0.8.

Note You need to log in before you can comment on or make changes to this bug.