Creating index slowly?

Showing 1-17 of 17 messages
Creating index slowly? Hanson Lu 8/20/12 7:49 PM
My collection currently has 40M records, and  i create a new compound index for it

The speed is 2512rec/sec. The insert speed for the collection is larger than 5k.

Is it normal? 

        "inprog" : [
                {
                        "opid" : 6,
                        "active" : true,
                        "lockType" : "write",
                        "waitingForLock" : false,
                        "secs_running" : 2081,
                        "op" : "insert",
                        "ns" : "cidb.system.indexes",
                        "query" : {

                        },
                        "client" : "127.0.0.1:57013",
                        "desc" : "conn",
                        "threadId" : "0x7f4ec0ff9710",
                        "connectionId" : 1,
                        "msg" : "bg index build 5228947/41882393 12%",
                        "progress" : {
                                "done" : 5228947,
                                "total" : 41882393
                        },
                        "numYields" : 814
                }

The collection has field like
{
   sender: "X",
   receiver:"Y",
   type:"TEXT",
   sendDate:"20120801020100"
  ...
}

I create index {sender:1,type:1,sendDate:-1}.

Th related topic i post is 

Hanson Lu 

Re: Creating index slowly? Hanson Lu 8/20/12 8:13 PM
The log show warning 
  "Tue Aug 21 07:09:27 [conn1] DR101 latency warning on journal file open 6605ms"

Data stored disk is local, not NFS.
Re: Creating index slowly? matts 8/23/12 1:21 PM
Can you run iostat during the insert operation and post the results here?
unk...@googlegroups.com 8/23/12 9:04 PM <This message has been deleted.>
Re: Creating index slowly? Hanson Lu 8/23/12 9:05 PM
Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.00   599.50    0.00  264.68     0.00     1.81    14.02   280.64 1141.55   3.76  99.50
sr0               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.00  1431.00    0.00  222.00     0.00     9.83    90.68   284.18 1099.77   4.51 100.20
sr0               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.00   119.90    0.00  250.75     0.00     1.41    11.56   282.28 1240.17   3.98  99.70
sr0               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00   0.00   0.00
Re: Creating index slowly? matts 8/24/12 2:15 PM
I assume that you created the index with background equals true? (so it is creating the index in the background while you are inserting 5k records)
What version of the system are you running?

your disks appear to be fully saturated.
unk...@googlegroups.com 8/24/12 5:32 PM <This message has been deleted.>
Re: Creating index slowly? Hanson Lu 8/24/12 5:35 PM
Yes, i created the index with background option. There is no inserting operation during creating index. 

 .
Re: Creating index slowly? Hanson Lu 8/24/12 7:32 PM
MongoDB version is 2.0.2,  linux 64bit 
Re: Creating index slowly? matts 8/27/12 4:09 PM
Can you try turning off background index creation and seeing if the latency warning still appears?
Re: Creating index slowly? Hanson Lu 9/10/12 6:42 PM
Sorry reply late , i just notice your post.

I turn off the background index creating, it seems no latency report  and i feel that  the speed is about twice as fast of the background indexing. 

This is iostat result  that remove the background option. 
Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.50   103.50   96.00   33.50    21.52     0.53   348.69     2.56   19.78   2.69  34.80

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           4.79    0.00    0.47    0.05    0.21   94.49

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               0.50     6.97   48.26    9.95    10.62     0.07   375.86     0.48    8.24   1.95  11.34

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           5.18    0.00    0.53    0.81    0.44   93.04

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               3.00  5998.50  250.00   11.00    55.68     2.22   454.34    28.98   12.83   2.43  63.40

I tested  IO performance of the disk, it shows  max wMB is about 40M, 

So i wonder why creating indexing with background option, the wMB is  low (9.83)?

the Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda                      0.00  1431.00    0.00  222.00     0.00     9.83    90.68   284.18 1099.77   4.51 100.20

unk...@googlegroups.com 9/10/12 6:47 PM <This message has been deleted.>
Re: Creating index slowly? Hanson Lu 9/10/12 6:48 PM
More iostat  data for creating indexing with no background option 

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               2.99  5867.66   42.79   82.09    10.21    22.24   532.18    79.02  612.02   7.86  98.11

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           5.04    0.00    0.61    1.34    0.55   92.46

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda               1.00   140.50  242.50   37.50    53.56     1.75   404.59     3.06   62.91   2.88  80.60

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           8.52    0.00    0.22    0.09    0.22   90.96

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda                0.00     1.00   70.00    0.50    15.27     0.01   443.74     0.24    3.38   1.93  13.60

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           4.53    0.00    0.29    0.10    0.22   94.87

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda                 1.49  5875.12   50.25   20.90    11.23     2.29   389.31    18.04   19.94   3.97  28.26

avg-cpu:  %user   %nice %system %iowait  %steal   %idle
           2.37    0.00    0.47    4.02    0.37   92.76

Device:         rrqm/s   wrqm/s     r/s     w/s    rMB/s    wMB/s avgrq-sz avgqu-sz   await  svctm  %util
sda                2.49    63.68   89.55   83.58    20.40    21.31   493.36    65.04  471.61   5.77  99.90
Re: Creating index slowly? Hanson Lu 9/10/12 7:45 PM
I saw two latency report at the end of creating 

Tue Sep 11 06:33:28 [conn1]      done building bottom layer, going to commit
Tue Sep 11 06:34:26 [conn1] old journal file will be removed: /home/user/mongo/mongodb/bin/../data/db/journal/j._1
Tue Sep 11 06:34:48 [conn1] DR101 latency warning on journal file open 18122ms
Tue Sep 11 06:36:34 [conn1] old journal file will be removed: /home/user/mongo/mongodb/bin/../data/db/journal/j._2
Tue Sep 11 06:36:40 [conn1] DR101 latency warning on journal file open 255ms
Tue Sep 11 06:36:47 [conn1] build index done 68885138 records 4109.42 secs
Re: Creating index slowly? David Hows 9/16/12 9:39 PM
Hi Hanson,

From the iostat output and the logs it would seem your disk hit a very heavy load, probably due to the removal of journal files and creation of index at the same time.

The last iostat you posted shows very heavy disk utilisation.

Are you still seeing these issues?

Cheers,

David
Re: Creating index slowly? Hanson Lu 9/17/12 11:58 PM
Hi David ,
 The both have heavy io utilization. But i noticed that the wMB/s(iostat) of indexing without background option is higher than that of indexing with background option. 
 
 So i think whether the writing operation is not optimized well for background indexing. 

 Actually the speed of background indexing is more worse than the data in my last post.

 It took more than 5 hours to create background index(40M records), only about 1-hour to create the same index without background option.

Regards 
Hanson
Re: Creating index slowly? David Hows 9/18/12 12:08 AM
Hi Hanson,

What you speak of is the tradeoff involved when using the background option.

If you create without background, it will go faster but will consume more IO.
If you create with background, it will take longer but consume less resources.

Hope that clears things up.

David