bzr fast-import performance slows over time

[Brian de Alwis]

Hi Ian.  With the new brisbane-core formats landed and your fast- 
import improvements, I thought I'd give importing the NetBSD  
repository another whirl.  I seem some interesting behaviour though --  
it starts off very fast (417 commits a minute!) and then slows down  
over time.  I've appended the log from the last 5 hours.  This  
repository has about 14 years of development, I believe this  
repository has many many heads, which may partially account for this.

This is still far speedier that the previous fast-import performance.

Brian.

15:30:11 progress 10000 objects
15:30:31 progress 20000 objects
15:32:10 1000 commits processed at 417/minute (:24354)
15:35:38 2000 commits processed at 341/minute (:29396)
15:37:57 progress 30000 objects
15:41:24 3000 commits processed at 258/minute (:37985)
15:43:07 progress 40000 objects
15:43:52 4000 commits processed at 284/minute (:41857)
15:45:44 5000 commits processed at 313/minute (:45272)
15:48:32 6000 commits processed at 320/minute (:48682)
15:49:38 progress 50000 objects
15:51:37 7000 commits processed at 320/minute (:52284)
15:54:41 8000 commits processed at 321/minute (:55780)
15:58:01 9000 commits processed at 319/minute (:59044)
15:58:43 progress 60000 objects
16:01:20 10000 commits processed at 317/minute (:62926)
16:01:20 10000 commits - automatic checkpoint triggered
16:08:55 11000 commits processed at 281/minute (:67838)
16:10:58 progress 70000 objects
16:12:04 12000 commits processed at 284/minute (:71105)
16:16:18 13000 commits processed at 279/minute (:76416)
16:20:28 progress 80000 objects
16:21:15 14000 commits processed at 272/minute (:80569)
16:25:32 15000 commits processed at 269/minute (:84878)
16:30:01 progress 90000 objects
16:30:05 16000 commits processed at 265/minute (:90039)
16:33:58 17000 commits processed at 265/minute (:93597)
16:38:32 18000 commits processed at 262/minute (:96941)
16:42:55 progress 100000 objects
16:45:10 19000 commits processed at 252/minute (:100659)
16:50:19 20000 commits processed at 248/minute (:104163)
16:50:19 20000 commits - automatic checkpoint triggered
16:58:13 21000 commits processed at 237/minute (:108086)
17:01:18 progress 110000 objects
17:05:30 22000 commits processed at 230/minute (:111997)
17:13:17 23000 commits processed at 222/minute (:115316)
17:23:57 24000 commits processed at 210/minute (:118248)
17:29:06 progress 120000 objects
17:31:53 25000 commits processed at 205/minute (:120877)
17:40:56 26000 commits processed at 198/minute (:125073)
17:52:27 27000 commits processed at 189/minute (:129490)
17:53:54 progress 130000 objects
18:05:45 28000 commits processed at 180/minute (:132884)
18:18:26 29000 commits processed at 172/minute (:136751)
18:30:20 30000 commits processed at 166/minute (:139399)
18:30:20 30000 commits - automatic checkpoint triggered
18:32:14 progress 140000 objects
18:39:35 31000 commits processed at 163/minute (:142809)
18:51:18 32000 commits processed at 159/minute (:146069)
19:03:41 33000 commits processed at 154/minute (:148961)
19:06:08 progress 150000 objects
19:15:03 34000 commits processed at 151/minute (:151892)
19:28:39 35000 commits processed at 147/minute (:155357)
19:39:01 36000 commits processed at 144/minute (:159499)
19:40:48 progress 160000 objects
19:52:00 37000 commits processed at 141/minute (:166438)
20:03:38 progress 170000 objects
20:07:08 38000 commits processed at 137/minute (:171634)
20:24:54 39000 commits processed at 132/minute (:175730)

-- 
"Amusement to an observing mind is study." - Benjamin Disraeli