Received: by 10.14.209.66 with SMTP id r42mr9241490eeo.1.1350210200839;
        Sun, 14 Oct 2012 03:23:20 -0700 (PDT)
X-BeenThere: redis-db@googlegroups.com
Received: by 10.14.219.66 with SMTP id l42ls2370341eep.6.gmail; Sun, 14 Oct
 2012 03:22:55 -0700 (PDT)
Received: by 10.14.204.3 with SMTP id g3mr9217090eeo.7.1350210175256;
        Sun, 14 Oct 2012 03:22:55 -0700 (PDT)
Received: by 10.14.204.3 with SMTP id g3mr9217087eeo.7.1350210175240;
        Sun, 14 Oct 2012 03:22:55 -0700 (PDT)
Return-Path: <aglad...@gmail.com>
Received: from mail-ee0-f50.google.com (mail-ee0-f50.google.com [74.125.83.50])
        by gmr-mx.google.com with ESMTPS id d5si1158847eep.0.2012.10.14.03.22.55
        (version=TLSv1/SSLv3 cipher=OTHER);
        Sun, 14 Oct 2012 03:22:55 -0700 (PDT)
Received-SPF: pass (google.com: domain of aglad...@gmail.com designates 74.125.83.50 as permitted sender) client-ip=74.125.83.50;
Authentication-Results: gmr-mx.google.com; spf=pass (google.com: domain of aglad...@gmail.com designates 74.125.83.50 as permitted sender) smtp.mail=aglad...@gmail.com; dkim=pass header...@gmail.com
Received: by mail-ee0-f50.google.com with SMTP id c41so2560881eek.37
        for <redis-db@googlegroups.com>; Sun, 14 Oct 2012 03:22:55 -0700 (PDT)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=gmail.com; s=20120113;
        h=mime-version:in-reply-to:references:from:date:message-id:subject:to
         :content-type;
        bh=6H/gg8qLsKZ4T3xUqVhgaWkArK9WMLEEhR0ssZFoyBY=;
        b=aYr4aNBoUClOLaP4lopfJRsvqTMoWgYPHU+WAs5mkEuz8r+GwBY2PeqLAaKGuXMhWT
         S1m9nKHhCaYAmdeAiSxNC3VnjENxbOUFwB3eJ65nPltPG8h/rJPJio3z0dnW/AQJ+bSv
         cej+C5C1/FpAJeAHjUHFD2NLzhuJAlFlufp6K1oZJptv0dHZtW1g9+1zMixfHNQjt2uq
         Fq0A+ayLaOe0ZlKcic2/Dm0Ml9moSvd2CI2zEciZYjEraDPcwXsXF2ljwjZ0G4nmLOZQ
         /iBXQz9UTChoH87VCE7Xw6Fer4Hi4POWx9WtgJ7PZX9RJ7uUEeBSrstld5igXt0NbPif
         ULTA==
Received: by 10.14.179.136 with SMTP id h8mr12010098eem.6.1350210175129; Sun,
 14 Oct 2012 03:22:55 -0700 (PDT)
MIME-Version: 1.0
Received: by 10.14.95.16 with HTTP; Sun, 14 Oct 2012 03:22:34 -0700 (PDT)
In-Reply-To: <CABZR_7Dsxi8X6F_hOzeFuwWTod5pkdBPQYTB08yTccUBS5p...@mail.gmail.com>
References: <CABZR_7Bx+f5hq+V8wN_dKnT-Z2SbUh5Ykfqy3AnD0We-Jb_...@mail.gmail.com>
 <CAH7wyv3Vb5yGa2FrckOgvA3b48YbydB+Mir-phanMz=MROv...@mail.gmail.com>
 <CABZR_7DfLsEiEjvxOAX8_ySzvx-PyY+HrtL0aqA0rM3ZE4b...@mail.gmail.com>
 <CA+XzkVcvmcKaXMa3S0wTAurAW-HmkVr-JTbd+o=0SoyH+_N...@mail.gmail.com> <CABZR_7Dsxi8X6F_hOzeFuwWTod5pkdBPQYTB08yTccUBS5p...@mail.gmail.com>
From: Alexander Gladysh <aglad...@gmail.com>
Date: Sun, 14 Oct 2012 14:22:34 +0400
Message-ID: <CABZR_7A3d4ZNE=JMW-K1xakJWx1VSYzXAYtt0cNKrmKP0P5...@mail.gmail.com>
Subject: Re: How to measure fork() time on bgrewriteaof?
To: redis-db@googlegroups.com
Content-Type: text/plain; charset=UTF-8

On Sun, Oct 14, 2012 at 1:39 PM, Alexander Gladysh <aglad...@gmail.com> wrote:
> On Sun, Oct 14, 2012 at 1:25 PM, Salvatore Sanfilippo <anti...@gmail.com> wrote:
>> On Sun, Oct 14, 2012 at 11:22 AM, Alexander Gladysh <aglad...@gmail.com> wrote:
>>
>>> That is 0.0001s, right? This means that fork is not a problem in my setup...
>>
>> No it is 0.1 seconds, so 100 milliseconds, still not a big deal
>> depending on your latency requirements.
>
> Well, that's more or less bearable. So, 10 seconds for BGREWRITEAOF
> here is probably HDD after all... (weird, dataset is about a
> gigabyte...)
>
> [755] 14 Oct 12:27:57 * Background append only file rewriting started
> by pid 21552
> [755] 14 Oct 12:28:01 * Asynchronous AOF fsync is taking too long
> (disk is busy?). Writing the AOF buffer without waiting for fsync to
> complete, this may slow down Redis.
> [755] 14 Oct 12:28:03 * Asynchronous AOF fsync is taking too long
> (disk is busy?). Writing the AOF buffer without waiting for fsync to
> complete, this may slow down Redis.
> [755] 14 Oct 12:28:06 * Asynchronous AOF fsync is taking too long
> (disk is busy?). Writing the AOF buffer without waiting for fsync to
> complete, this may slow down Redis.
> [21552] 14 Oct 12:28:07 * SYNC append only file rewrite performed
> [755] 14 Oct 12:28:07 * Background AOF rewrite terminated with success
> [755] 14 Oct 12:28:07 * Parent diff successfully flushed to the
> rewritten AOF (436762 bytes)
> [755] 14 Oct 12:28:07 * Background AOF rewrite successful

BTW, is there a way to conclusively *prove* that this is due to HDD? I
see consistently 7-10 seconds per rewrite.

I already asked something along these lines recently here, but there
were no *concrete* answers (or I missed them). Sorry for lazyish
question, answers "read my post [link] again and do your homework" are
accepted (but if someone can give specifics, it will be much
appreciated).

Thanks,
Alexander.