Received: by 10.42.33.9 with SMTP id g9mr4450343icd.25.1353082240675;
Fri, 16 Nov 2012 08:10:40 -0800 (PST)
X-BeenThere: mongodb-user@googlegroups.com
Received: by 10.50.53.173 with SMTP id c13ls1005529igp.38.gmail; Fri, 16 Nov
2012 08:10:21 -0800 (PST)
Received: by 10.50.108.200 with SMTP id hm8mr1521658igb.10.1353082221449;
Fri, 16 Nov 2012 08:10:21 -0800 (PST)
Date: Fri, 16 Nov 2012 08:10:20 -0800 (PST)
From: Tim Haines <tmhai...@gmail.com>
To: mongodb-user@googlegroups.com
Message-Id: <0bf7d4a6-c916-4f8f-a4bd-155920634c6b@googlegroups.com>
In-Reply-To: <CAD48p-T6ddhyZPqgu_AQepLC8By7B6Bp+su795WwmZo2ehZ-_g@mail.gmail.com>
References: <f0b9a414-c98b-449f-8551-558d41ea7e28@googlegroups.com>
<fb1a08d3-9fad-4236-9704-232a5e5ca6e5@googlegroups.com>
<CA+buB7cM-sETam0nA=oDb+R_VvfJV-kEWhKSk2vssrNuJ7pL-A@mail.gmail.com>
<da026cbd-c653-4494-8e03-e67c933d8942@googlegroups.com>
<63e5fdea-020a-4728-b774-8357147e88d5@googlegroups.com>
<CAD48p-Q7v_34L2TmCEqeL7KFLNJH03o0pzj8SP38waAPH30VCQ@mail.gmail.com>
<1afc3883-0c21-46f1-9356-e96694ddced9@googlegroups.com>
<CAD48p-T6ddhyZPqgu_AQepLC8By7B6Bp+su795WwmZo2ehZ-_g@mail.gmail.com>
Subject: Re: [mongodb-user] Re: inconsistent read speed - logs with flushing
mmaps took 11205ms in the log
MIME-Version: 1.0
Content-Type: multipart/mixed;
boundary="----=_Part_1615_24026571.1353082220989"
------=_Part_1615_24026571.1353082220989
Content-Type: multipart/alternative;
boundary="----=_Part_1616_20550074.1353082220989"
------=_Part_1616_20550074.1353082220989
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 7bit
Hi Gevorg,
I don't have indexes on the arrays. I did have 4 index on other fields,
but I tried dropping them and I still see similar messages - though with
slightly smaller durations. My dataset is still smaller than RAM (8GB) -
so I'll be very curios to see what happens once it's larger than RAM.
Probably in 2 - 3 more days.
I'll see if I can spin up a test with 2.0.8 as well, but I'm going on
vacation later today, so it might take a bit of time.
Tim.
On Friday, November 16, 2012 7:59:12 AM UTC-8, Gevorg Hari wrote:
>
> Tim,
>
> my documents contain arrays of documents but the average length is about
> 20/30. Each document in the array has about 10 string fields and I have
> (I'm trying to have) two separate indexes on two of those. The collection
> contains ~50M documents. I started having serious issues when I tried to
> create the second index and eventually I had to abort the operation.
>
> I saw way less issues with the 2.0.8-rc0 version (try to create a parallel
> instance if you can and see if it makes any difference for you) but
> creating the second index (sparse, background) was still too painful. I
> wiped out everything, created the indexes first, and trying to reinsert the
> data to see if it makes any difference right now. The RAM jumped up to 100%
> after a few hours and the server is not doing great but I'll wait and see
> what happens.
>
> Do you have indexes as well on those arrays?
>
>
> On Fri, Nov 16, 2012 at 10:42 AM, Tim Haines <tmha...@gmail.com<javascript:>
> > wrote:
>
>> Hi Gevorg,
>>
>> Do your documents contain large arrays by any chance? A portion of mine
>> do and grow up to 1000 - 3000 elements, but some stay at 1. They start
>> with 1 element and I grow them 1 element at a time with push. I'm
>> wondering if this is related to the problem.
>>
>> Tim.
>>
>>
>> On Friday, November 16, 2012 7:38:28 AM UTC-8, Gevorg Hari wrote:
>>
>>> I downgraded to 2.0.8-rc0 and that specific problem seems to be gone.
>>> There is a similar (maybe equivalent) message: "FlushViewOfFile for
>>> ../datadb/collection_name.**number" that takes way less time and seems
>>> not to freeze the db. This is while creating indexes on big collections.
>>>
>>> In both versions (2.2.1 and 2.0.8-rc0) the RAM utilization jumps up to
>>> 100% after a while and the entire server becomes scaringly slow. This
>>> affects every other process running on the server and it doesn't let me
>>> connect to the machine (remote desktop) in an acceptable amount of time. I
>>> noticing this issue right now while inserting large amounts of data in the
>>> db (not using mongoimport for several reasons).
>>>
>>>
>>>
>>> On Thu, Nov 15, 2012 at 4:32 PM, Tim Haines <tmha...@gmail.com> wrote:
>>>
>>>> Removing the 4 indexes hasn't helped either. Flushing the mmaps is
>>>> still taking 10 - 20 seconds, write performance is spikey, and single reads
>>>> spike up to over 1 second.
>>>>
>>>>
>>>> On Thursday, November 15, 2012 11:31:20 AM UTC-8, Tim Haines wrote:
>>>>>
>>>>> I'm running Ubuntu 12.04 and ext4.
>>>>>
>>>>> I've tried running mongostat this morning to get more insight into how
>>>>> performance is being affected.
>>>>>
>>>>> It's doing about 4000 write ops per second when there's no disk
>>>>> activity. Unfortunately these are only in bursts of about 10 seconds now,
>>>>> followed by 40 seconds of high disk io while flushing the mmaps. While the
>>>>> flush is occurring, the write ops drop to 500 - 1000 per second,
>>>>> with occasional drops to 0.
>>>>>
>>>>> I'm wondering if moving the journal files to another drive would
>>>>> alleviate this much.
>>>>>
>>>>> Tim.
>>>>>
>>>>>
>>>>>
>>>>> On Thursday, November 15, 2012 11:08:45 AM UTC-8, Jason Lewis wrote:
>>>>>>
>>>>>> What OS and filesystem?
>>>>>>
>>>>>> On Thu, Nov 15, 2012 at 11:34 AM, Tim Haines <tmha...@gmail.com>
>>>>>> wrote:
>>>>>> > The mmap flushing is even slower now..
>>>>>> >
>>>>>> > Thu Nov 15 10:25:50 [journal] old journal file will be removed:
>>>>>> > /var/lib/mongodb/journal/j._79
>>>>>> > Thu Nov 15 10:25:51 [journal] DR101 latency warning on journal file
>>>>>> open
>>>>>> > 562ms
>>>>>> > Thu Nov 15 10:26:40 [DataFileSync] flushing mmaps took 27696ms for
>>>>>> 14 files
>>>>>> > Thu Nov 15 10:27:50 [DataFileSync] flushing mmaps took 37244ms for
>>>>>> 14 files
>>>>>> > Thu Nov 15 10:28:48 [DataFileSync] flushing mmaps took 35968ms for
>>>>>> 14 files
>>>>>> > Thu Nov 15 10:29:01 [journal] old journal file will be removed:
>>>>>> > /var/lib/mongodb/journal/j._80
>>>>>> > Thu Nov 15 10:29:38 [DataFileSync] flushing mmaps took 25631ms for
>>>>>> 14 files
>>>>>> > Thu Nov 15 10:30:35 [DataFileSync] flushing mmaps took 22286ms for
>>>>>> 14 files
>>>>>> > Thu Nov 15 10:31:50 [DataFileSync] flushing mmaps took 37886ms for
>>>>>> 14 files
>>>>>> >
>>>>>> > Tim.
>>>>>> >
>>>>>> > On Wednesday, November 14, 2012 8:46:42 PM UTC-8, Tim Haines wrote:
>>>>>> >>
>>>>>> >> Hi there,
>>>>>> >>
>>>>>> >> I've plugged mongo into my production system today to see how it
>>>>>> handles
>>>>>> >> the write speed for a few days. So far I only have one server
>>>>>> with a 15k
>>>>>> >> RPM spinning disk and 8GB of ram. If I take this to production
>>>>>> properly, I
>>>>>> >> intend to shard, but hopefully to only 2 or 3 servers.
>>>>>> >>
>>>>>> >> Right now I'm doing about 200 upsert findAndModify's per second,
>>>>>> and 200
>>>>>> >> upsert updates. The stats tells me the averageObjSize is 129
>>>>>> bytes for the
>>>>>> >> documents receiving findAndModifys (4 indexes) and 91 bytes for
>>>>>> the
>>>>>> >> documents receiving updates (1 index). The dataset (data +
>>>>>> indexes) is
>>>>>> >> currently around 1GB in total.
>>>>>> >>
>>>>>> >> I have these entries in the mongo logs - I don't know what they
>>>>>> mean yet,
>>>>>> >> but they're concerning:
>>>>>> >>
>>>>>> >> Wed Nov 14 21:49:23 [DataFileSync] flushing mmaps took 10482ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 21:53:23 [DataFileSync] flushing mmaps took 10520ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 21:55:07 [websvr] serverStatus was very slow: { after
>>>>>> basic: 0,
>>>>>> >> middle of mem: 1640, after mem: 1640, after connections: 1640,
>>>>>> after extra
>>>>>> >> info: 1640, after counters: 1640, after repl: 1640, after asserts:
>>>>>> 1640,
>>>>>> >> after dur: 1640, at end: 1640 }
>>>>>> >> Wed Nov 14 21:56:22 [DataFileSync] flushing mmaps took 10078ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 21:57:04 [journal] old journal file will be removed:
>>>>>> >> /var/lib/mongodb/journal/j._46
>>>>>> >> Wed Nov 14 21:57:22 [DataFileSync] flushing mmaps took 10008ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 22:00:23 [DataFileSync] flushing mmaps took 10751ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 22:01:23 [DataFileSync] flushing mmaps took 11075ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 22:05:11 [journal] old journal file will be removed:
>>>>>> >> /var/lib/mongodb/journal/j._47
>>>>>> >> Wed Nov 14 22:06:23 [DataFileSync] flushing mmaps took 10347ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 22:07:24 [DataFileSync] flushing mmaps took 11479ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 22:10:23 [DataFileSync] flushing mmaps took 10410ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 22:11:23 [DataFileSync] flushing mmaps took 10340ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 22:13:24 [DataFileSync] flushing mmaps took 11128ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 22:13:27 [journal] old journal file will be removed:
>>>>>> >> /var/lib/mongodb/journal/j._48
>>>>>> >> Wed Nov 14 22:14:24 [DataFileSync] flushing mmaps took 11807ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >> Wed Nov 14 22:15:24 [DataFileSync] flushing mmaps took 11205ms
>>>>>> for 11
>>>>>> >> files
>>>>>> >>
>>>>>> >> I'm not doing any reads yet, but I decided to check to see how
>>>>>> consistent
>>>>>> >> they are - if the mmaps flushing is causing read stalls.
>>>>>> >>
>>>>>> >> I set up a simple query which fetches one record based on an
>>>>>> index, and
>>>>>> >> had it repeat every second. I log the duration and timestamp if
>>>>>> it took
>>>>>> >> longer than 3ms (most were under 1ms). This is the output I saw -
>>>>>> some
>>>>>> >> operations taking multiple seconds for a single record query based
>>>>>> on an
>>>>>> >> index. Where all the data and indexes should still be in ram..
>>>>>> >>
>>>>>> >> 0.104574109 2012-11-14 22:13:54 -0600
>>>>>> >> 4.74783542 2012-11-14 22:14:22 -0600
>>>>>> >> 0.243556581 2012-11-14 22:14:25 -0600
>>>>>> >> 0.821347295 2012-11-14 22:14:30 -0600
>>>>>> >> 0.036629986 2012-11-14 22:14:56 -0600
>>>>>> >> 3.851662545 2012-11-14 22:15:05 -0600
>>>>>> >> 0.007991038 2012-11-14 22:15:10 -0600
>>>>>> >> 0.004475775 2012-11-14 22:15:57 -0600
>>>>>> >> 0.09404014 2012-11-14 22:16:00 -0600
>>>>>> >> 0.004445754 2012-11-14 22:16:07 -0600
>>>>>> >> 0.024827767 2012-11-14 22:16:16 -0600
>>>>>> >> 0.004718648 2012-11-14 22:16:29 -0600
>>>>>> >> 0.543830541 2012-11-14 22:16:48 -0600
>>>>>> >> 0.081387443 2012-11-14 22:16:57 -0600
>>>>>> >> 0.093996291 2012-11-14 22:17:55 -0600
>>>>>> >> 0.013581206 2012-11-14 22:18:01 -0600
>>>>>> >> 0.455109956 2012-11-14 22:18:17 -0600
>>>>>> >> 0.543997559 2012-11-14 22:18:20 -0600
>>>>>> >> 0.006581586 2012-11-14 22:18:27 -0600
>>>>>> >> 0.040279709 2012-11-14 22:18:52 -0600
>>>>>> >> 3.9563892 2012-11-14 22:19:22 -0600
>>>>>> >> 0.08867152 2012-11-14 22:19:36 -0600
>>>>>> >> 0.044744453 2012-11-14 22:19:54 -0600
>>>>>> >> 0.011553574 2012-11-14 22:20:14 -0600
>>>>>> >> 0.151064978 2012-11-14 22:20:50 -0600
>>>>>> >>
>>>>>> >> My munin graph shows disk utilization is at 33%. iostat often
>>>>>> reports
>>>>>> >> util at 0% - 2%, but has bursts at 100%.
>>>>>> >>
>>>>>> >> Is it possible I have something misconfigured here or is there
>>>>>> something I
>>>>>> >> likely need to tune? Am I overloading the machine? It's my first
>>>>>> day
>>>>>> >> throwing data at mongo, so if someone more experienced could offer
>>>>>> any
>>>>>> >> insight, it would be much appreciated.
>>>>>> >>
>>>>>> >> Cheers,
>>>>>> >>
>>>>>> >> Tim
>>>>>> >
>>>>>> > --
>>>>>> > You received this message because you are subscribed to the Google
>>>>>> > Groups "mongodb-user" group.
>>>>>> > To post to this group, send email to mongod...@googlegroups.com
>>>>>> > To unsubscribe from this group, send email to
>>>>>> > mongodb-user...@googlegroups.**c**om
>>>>>> > See also the IRC channel -- freenode.net#mongodb
>>>>>>
>>>>> --
>>>> You received this message because you are subscribed to the Google
>>>> Groups "mongodb-user" group.
>>>> To post to this group, send email to mongod...@googlegroups.com
>>>> To unsubscribe from this group, send email to
>>>> mongodb-user...@**googlegroups.com
>>>> See also the IRC channel -- freenode.net#mongodb
>>>>
>>>
>>> --
>> You received this message because you are subscribed to the Google
>> Groups "mongodb-user" group.
>> To post to this group, send email to mongod...@googlegroups.com<javascript:>
>> To unsubscribe from this group, send email to
>> mongodb-user...@googlegroups.com <javascript:>
>> See also the IRC channel -- freenode.net#mongodb
>>
>
>
------=_Part_1616_20550074.1353082220989
Content-Type: text/html; charset=utf-8
Content-Transfer-Encoding: quoted-printable
Hi Gevorg,<div><br></div><div>I don't have indexes on the arrays. I d=
id have 4 index on other fields, but I tried dropping them and I still see =
similar messages - though with slightly smaller durations. My dataset=
is still smaller than RAM (8GB) - so I'll be very curios to see what happe=
ns once it's larger than RAM. Probably in 2 - 3 more days. </di=
v><div><br></div><div>I'll see if I can spin up a test with 2.0.8 as well, =
but I'm going on vacation later today, so it might take a bit of time.</div=
><div><br></div><div>Tim.</div><div><br></div><div><br><br>On Friday, Novem=
ber 16, 2012 7:59:12 AM UTC-8, Gevorg Hari wrote:<blockquote class=3D"gmail=
_quote" style=3D"margin: 0;margin-left: 0.8ex;border-left: 1px #ccc solid;p=
adding-left: 1ex;">Tim,<div><br></div><div>my documents contain arrays of d=
ocuments but the average length is about 20/30. Each document in the array =
has about 10 string fields and I have (I'm trying to have) two separate ind=
exes on two of those. The collection contains ~50M documents. I started hav=
ing serious issues when I tried to create the second index and eventually I=
had to abort the operation. </div>
<div><br></div><div>I saw way less issues with the 2.0.8-rc0 version (try t=
o create a parallel instance if you can and see if it makes any difference =
for you) but creating the second index (sparse, background) was still too p=
ainful. I wiped out everything, created the indexes first, and trying to re=
insert the data to see if it makes any difference right now. The RAM jumped=
up to 100% after a few hours and the server is not doing great but I'll wa=
it and see what happens.</div>
<div><br></div><div>Do you have indexes as well on those arrays?</div><div>=
<br><br><div class=3D"gmail_quote">On Fri, Nov 16, 2012 at 10:42 AM, Tim Ha=
ines <span dir=3D"ltr"><<a href=3D"javascript:" target=3D"_blank" gdf-ob=
fuscated-mailto=3D"4uN7tRYiZ1oJ">tmha...@gmail.com</a>></span> wrote:<br=
>
<blockquote class=3D"gmail_quote" style=3D"margin:0 0 0 .8ex;border-left:1p=
x #ccc solid;padding-left:1ex">Hi Gevorg,<div><br></div><div>Do your docume=
nts contain large arrays by any chance? A portion of mine do and grow=
up to 1000 - 3000 elements, but some stay at 1. They start with 1 el=
ement and I grow them 1 element at a time with push. I'm wondering if=
this is related to the problem.</div>
<span><font color=3D"#888888"><div><br></div></font></span><div><span><font=
color=3D"#888888">Tim.</font></span><div><br><br>On Friday, November 16, 2=
012 7:38:28 AM UTC-8, Gevorg Hari wrote:</div>
<blockquote class=3D"gmail_quote" style=3D"margin:0;margin-left:0.8ex;borde=
r-left:1px #ccc solid;padding-left:1ex"><div>I downgraded to 2.0.8-rc0 and =
that specific problem seems to be gone. There is a similar (maybe equivalen=
t) message: "FlushViewOfFile for ../datadb/collection_name.<u></u>numb<wbr>=
er" that takes way less time and seems not to freeze the db. This is while =
creating indexes on big collections.<div>
<br></div><div>In both versions (2.2.1 and 2.0.8-rc0) the RAM utilization j=
umps up to 100% after a while and the entire server becomes scaringly slow.=
This affects every other process running on the server and it doesn't let =
me connect to the machine (remote desktop) in an acceptable amount of time.=
I noticing this issue right now while inserting large amounts of data in t=
he db (not using mongoimport for several reasons).</div>
<div><br></div></div><div><div><div><br><br><div class=3D"gmail_quote">On T=
hu, Nov 15, 2012 at 4:32 PM, Tim Haines <span dir=3D"ltr"><<a>tmha...@gm=
ail.com</a>></span> wrote:<br>
<blockquote class=3D"gmail_quote" style=3D"margin:0 0 0 .8ex;border-left:1p=
x #ccc solid;padding-left:1ex">Removing the 4 indexes hasn't helped either.=
Flushing the mmaps is still taking 10 - 20 seconds, write performanc=
e is spikey, and single reads spike up to over 1 second. <div>
<div><br><br>On Thursday, November 15, 2012 11:31:20 AM UTC-8, Tim Haines w=
rote:<blockquote class=3D"gmail_quote" style=3D"margin:0;margin-left:0.8ex;=
border-left:1px #ccc solid;padding-left:1ex">I'm running Ubuntu 12.04 and e=
xt4.<div>
<br></div><div>I've tried running mongostat this morning to get more insigh=
t into how performance is being affected.</div><div><br></div><div>It's doi=
ng about 4000 write ops per second when there's no disk activity. Unf=
ortunately these are only in bursts of about 10 seconds now, followed by 40=
seconds of high disk io while flushing the mmaps. While the flush is=
occurring, the write ops drop to 500 - 1000 per second, with occasion=
al drops to 0.</div>
<div><br></div><div>I'm wondering if moving the journal files to another dr=
ive would alleviate this much. </div><div><br></div><div>Tim.</div><di=
v><br></div><div><br><br>On Thursday, November 15, 2012 11:08:45 AM UTC-8, =
Jason Lewis wrote:<blockquote class=3D"gmail_quote" style=3D"margin:0;margi=
n-left:0.8ex;border-left:1px #ccc solid;padding-left:1ex">
What OS and filesystem?
<br>
<br>On Thu, Nov 15, 2012 at 11:34 AM, Tim Haines <<a>tmha...@gmail.com</=
a>> wrote:
<br>> The mmap flushing is even slower now..
<br>>
<br>> Thu Nov 15 10:25:50 [journal] old journal file will be removed:
<br>> /var/lib/mongodb/journal/j._79
<br>> Thu Nov 15 10:25:51 [journal] DR101 latency warning on journal fil=
e open
<br>> 562ms
<br>> Thu Nov 15 10:26:40 [DataFileSync] flushing mmaps took 27696ms &nb=
sp;for 14 files
<br>> Thu Nov 15 10:27:50 [DataFileSync] flushing mmaps took 37244ms &nb=
sp;for 14 files
<br>> Thu Nov 15 10:28:48 [DataFileSync] flushing mmaps took 35968ms &nb=
sp;for 14 files
<br>> Thu Nov 15 10:29:01 [journal] old journal file will be removed:
<br>> /var/lib/mongodb/journal/j._80
<br>> Thu Nov 15 10:29:38 [DataFileSync] flushing mmaps took 25631ms &nb=
sp;for 14 files
<br>> Thu Nov 15 10:30:35 [DataFileSync] flushing mmaps took 22286ms &nb=
sp;for 14 files
<br>> Thu Nov 15 10:31:50 [DataFileSync] flushing mmaps took 37886ms &nb=
sp;for 14 files
<br>>
<br>> Tim.
<br>>
<br>> On Wednesday, November 14, 2012 8:46:42 PM UTC-8, Tim Haines wrote=
:
<br>>>
<br>>> Hi there,
<br>>>
<br>>> I've plugged mongo into my production system today to see how =
it handles
<br>>> the write speed for a few days. So far I only have one s=
erver with a 15k
<br>>> RPM spinning disk and 8GB of ram. If I take this to prod=
uction properly, I
<br>>> intend to shard, but hopefully to only 2 or 3 servers.
<br>>>
<br>>> Right now I'm doing about 200 upsert findAndModify's per secon=
d, and 200
<br>>> upsert updates. The stats tells me the averageObjSize is=
129 bytes for the
<br>>> documents receiving findAndModifys (4 indexes) and 91 bytes fo=
r the
<br>>> documents receiving updates (1 index). The dataset (data=
+ indexes) is
<br>>> currently around 1GB in total.
<br>>>
<br>>> I have these entries in the mongo logs - I don't know what the=
y mean yet,
<br>>> but they're concerning:
<br>>>
<br>>> Wed Nov 14 21:49:23 [DataFileSync] flushing mmaps took 10482ms=
for 11
<br>>> files
<br>>> Wed Nov 14 21:53:23 [DataFileSync] flushing mmaps took 10520ms=
for 11
<br>>> files
<br>>> Wed Nov 14 21:55:07 [websvr] serverStatus was very slow: { aft=
er basic: 0,
<br>>> middle of mem: 1640, after mem: 1640, after connections: 1640,=
after extra
<br>>> info: 1640, after counters: 1640, after repl: 1640, after asse=
rts: 1640,
<br>>> after dur: 1640, at end: 1640 }
<br>>> Wed Nov 14 21:56:22 [DataFileSync] flushing mmaps took 10078ms=
for 11
<br>>> files
<br>>> Wed Nov 14 21:57:04 [journal] old journal file will be removed=
:
<br>>> /var/lib/mongodb/journal/j._46
<br>>> Wed Nov 14 21:57:22 [DataFileSync] flushing mmaps took 10008ms=
for 11
<br>>> files
<br>>> Wed Nov 14 22:00:23 [DataFileSync] flushing mmaps took 10751ms=
for 11
<br>>> files
<br>>> Wed Nov 14 22:01:23 [DataFileSync] flushing mmaps took 11075ms=
for 11
<br>>> files
<br>>> Wed Nov 14 22:05:11 [journal] old journal file will be removed=
:
<br>>> /var/lib/mongodb/journal/j._47
<br>>> Wed Nov 14 22:06:23 [DataFileSync] flushing mmaps took 10347ms=
for 11
<br>>> files
<br>>> Wed Nov 14 22:07:24 [DataFileSync] flushing mmaps took 11479ms=
for 11
<br>>> files
<br>>> Wed Nov 14 22:10:23 [DataFileSync] flushing mmaps took 10410ms=
for 11
<br>>> files
<br>>> Wed Nov 14 22:11:23 [DataFileSync] flushing mmaps took 10340ms=
for 11
<br>>> files
<br>>> Wed Nov 14 22:13:24 [DataFileSync] flushing mmaps took 11128ms=
for 11
<br>>> files
<br>>> Wed Nov 14 22:13:27 [journal] old journal file will be removed=
:
<br>>> /var/lib/mongodb/journal/j._48
<br>>> Wed Nov 14 22:14:24 [DataFileSync] flushing mmaps took 11807ms=
for 11
<br>>> files
<br>>> Wed Nov 14 22:15:24 [DataFileSync] flushing mmaps took 11205ms=
for 11
<br>>> files
<br>>>
<br>>> I'm not doing any reads yet, but I decided to check to see how=
consistent
<br>>> they are - if the mmaps flushing is causing read stalls.
<br>>>
<br>>> I set up a simple query which fetches one record based on an i=
ndex, and
<br>>> had it repeat every second. I log the duration and times=
tamp if it took
<br>>> longer than 3ms (most were under 1ms). This is the outpu=
t I saw - some
<br>>> operations taking multiple seconds for a single record query b=
ased on an
<br>>> index. Where all the data and indexes should still be in=
ram..
<br>>>
<br>>> 0.104574109 2012-11-14 22:13:54 -0600
<br>>> 4.74783542 2012-11-14 22:14:22 -0600
<br>>> 0.243556581 2012-11-14 22:14:25 -0600
<br>>> 0.821347295 2012-11-14 22:14:30 -0600
<br>>> 0.036629986 2012-11-14 22:14:56 -0600
<br>>> 3.851662545 2012-11-14 22:15:05 -0600
<br>>> 0.007991038 2012-11-14 22:15:10 -0600
<br>>> 0.004475775 2012-11-14 22:15:57 -0600
<br>>> 0.09404014 2012-11-14 22:16:00 -0600
<br>>> 0.004445754 2012-11-14 22:16:07 -0600
<br>>> 0.024827767 2012-11-14 22:16:16 -0600
<br>>> 0.004718648 2012-11-14 22:16:29 -0600
<br>>> 0.543830541 2012-11-14 22:16:48 -0600
<br>>> 0.081387443 2012-11-14 22:16:57 -0600
<br>>> 0.093996291 2012-11-14 22:17:55 -0600
<br>>> 0.013581206 2012-11-14 22:18:01 -0600
<br>>> 0.455109956 2012-11-14 22:18:17 -0600
<br>>> 0.543997559 2012-11-14 22:18:20 -0600
<br>>> 0.006581586 2012-11-14 22:18:27 -0600
<br>>> 0.040279709 2012-11-14 22:18:52 -0600
<br>>> 3.9563892 2012-11-14 22:19:22 -0600
<br>>> 0.08867152 2012-11-14 22:19:36 -0600
<br>>> 0.044744453 2012-11-14 22:19:54 -0600
<br>>> 0.011553574 2012-11-14 22:20:14 -0600
<br>>> 0.151064978 2012-11-14 22:20:50 -0600
<br>>>
<br>>> My munin graph shows disk utilization is at 33%. iostat =
often reports
<br>>> util at 0% - 2%, but has bursts at 100%.
<br>>>
<br>>> Is it possible I have something misconfigured here or is there=
something I
<br>>> likely need to tune? Am I overloading the machine?  =
;It's my first day
<br>>> throwing data at mongo, so if someone more experienced could o=
ffer any
<br>>> insight, it would be much appreciated.
<br>>>
<br>>> Cheers,
<br>>>
<br>>> Tim
<br>>
<br>> --
<br>> You received this message because you are subscribed to the Google
<br>> Groups "mongodb-user" group.
<br>> To post to this group, send email to <a>mongod...@googlegroups.com=
</a>
<br>> To unsubscribe from this group, send email to
<br>> <a>mongodb-user...@googlegroups.<u></u>c<u></u><wbr>om</a>
<br>> See also the IRC channel -- <a href=3D"http://freenode.net#mongodb=
" target=3D"_blank">freenode.net#mongodb</a>
<br></blockquote></div></blockquote>
<p></p>
-- <br>
You received this message because you are subscribed to the Google<br>
Groups "mongodb-user" group.<br>
To post to this group, send email to <a>mongod...@googlegroups.com</a><br>
To unsubscribe from this group, send email to<br>
<a>mongodb-user...@<u></u>googlegroups.<wbr>com</a><br>
See also the IRC channel -- <a href=3D"http://freenode.net#mongodb" target=
=3D"_blank">freenode.net#mongodb</a><br>
</div></div></blockquote></div><br></div>
</div></div></blockquote></div><div><div>
<p></p>
-- <br>
You received this message because you are subscribed to the Google<br>
Groups "mongodb-user" group.<br>
To post to this group, send email to <a href=3D"javascript:" target=3D"_bla=
nk" gdf-obfuscated-mailto=3D"4uN7tRYiZ1oJ">mongod...@googlegroups.com</a><b=
r>
To unsubscribe from this group, send email to<br>
<a href=3D"javascript:" target=3D"_blank" gdf-obfuscated-mailto=3D"4uN7tRYi=
Z1oJ">mongodb-user...@<wbr>googlegroups.com</a><br>
See also the IRC channel -- <a href=3D"http://freenode.net#mongodb" target=
=3D"_blank">freenode.net#mongodb</a><br>
</div></div></blockquote></div><br></div>
</blockquote></div>
------=_Part_1616_20550074.1353082220989--
------=_Part_1615_24026571.1353082220989--
Message from discussion inconsistent read speed - logs with flushing mmaps took 11205ms in the log
| Create a group - Google Groups - Google Home - Terms of Service - Privacy Policy |
| ©2013 Google |