You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@kafka.apache.org by Jason Rosenberg <jb...@squareup.com> on 2013/05/23 06:45:44 UTC
large amount of disk space freed on restart
Normally, I see 2-4 log segments deleted every hour in my brokers. I see
log lines like this:
2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0] log.LogManager -
Deleting log segment 00000000035434043157.kafka from <redacted topic>
However, it seems like if I restart the broker, a massive amount of disk
space is freed (without a corresponding flood of these log segment deleted
messages). Is there an explanation for this? Does kafka keep reference to
file segments around, and reuse them as needed or something? And then or
restart, the references to those free segment files are dropped?
Thoughts?
This is with 0.7.2.
Jason
Re: large amount of disk space freed on restart
Posted by Jason Rosenberg <jb...@squareup.com>.
No, nothing outside of kafka would look at those files....
I'm wondering if it's an os level thing too....
On Wed, May 22, 2013 at 10:25 PM, Jonathan Creasy <jc...@box.com> wrote:
> Well, it sounds like files were deleted while Kafka still had them open.
> Or something else opened them while Kafka deleted them. I haven't noticed
> this on our systems but we haven't looked for it either.
>
> Is anything outside of Kafka deleting or reading those files?
> On May 23, 2013 1:17 AM, "Jason Rosenberg" <jb...@squareup.com> wrote:
>
>> So, does this indicate kafka (or the jvm itself) is not aggressively
>> closing file handles of deleted files? Is there a fix for this? Or is
>> there not likely anything to be done? What happens if the disk fills up
>> with file handles for phantom deleted files?
>>
>> Jason
>>
>>
>> On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <jc...@box.com> wrote:
>>
>>> It isn't uncommon if a process has an open file handle on a file that is
>>> deleted, the space is not freed until the handle is closed. So restarting
>>> the process that has a handle on the file would cause the space to be
>>> freed
>>> also.
>>>
>>> You can troubleshoot that with lsof.
>>> Normally, I see 2-4 log segments deleted every hour in my brokers. I see
>>> log lines like this:
>>>
>>> 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0] log.LogManager -
>>> Deleting log segment 00000000035434043157.kafka from <redacted topic>
>>>
>>> However, it seems like if I restart the broker, a massive amount of disk
>>> space is freed (without a corresponding flood of these log segment
>>> deleted
>>> messages). Is there an explanation for this? Does kafka keep reference
>>> to
>>> file segments around, and reuse them as needed or something? And then or
>>> restart, the references to those free segment files are dropped?
>>>
>>> Thoughts?
>>>
>>> This is with 0.7.2.
>>>
>>> Jason
>>>
>>
>>
Re: large amount of disk space freed on restart
Posted by Jonathan Creasy <jc...@box.com>.
Well, it sounds like files were deleted while Kafka still had them open. Or
something else opened them while Kafka deleted them. I haven't noticed this
on our systems but we haven't looked for it either.
Is anything outside of Kafka deleting or reading those files?
On May 23, 2013 1:17 AM, "Jason Rosenberg" <jb...@squareup.com> wrote:
> So, does this indicate kafka (or the jvm itself) is not aggressively
> closing file handles of deleted files? Is there a fix for this? Or is
> there not likely anything to be done? What happens if the disk fills up
> with file handles for phantom deleted files?
>
> Jason
>
>
> On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <jc...@box.com> wrote:
>
>> It isn't uncommon if a process has an open file handle on a file that is
>> deleted, the space is not freed until the handle is closed. So restarting
>> the process that has a handle on the file would cause the space to be
>> freed
>> also.
>>
>> You can troubleshoot that with lsof.
>> Normally, I see 2-4 log segments deleted every hour in my brokers. I see
>> log lines like this:
>>
>> 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0] log.LogManager -
>> Deleting log segment 00000000035434043157.kafka from <redacted topic>
>>
>> However, it seems like if I restart the broker, a massive amount of disk
>> space is freed (without a corresponding flood of these log segment deleted
>> messages). Is there an explanation for this? Does kafka keep reference
>> to
>> file segments around, and reuse them as needed or something? And then or
>> restart, the references to those free segment files are dropped?
>>
>> Thoughts?
>>
>> This is with 0.7.2.
>>
>> Jason
>>
>
>
Re: large amount of disk space freed on restart
Posted by Mike Heffner <mi...@librato.com>.
Jason,
Thanks, we'll give that option a try.
Mike
On Mon, Sep 9, 2013 at 2:41 PM, Jason Rosenberg <jb...@squareup.com> wrote:
> Sorry, I forgot to close the loop on my experiences with this....
>
> We solved this issue by setting the 'allocsize' mount option, in the fstab.
> E.g. allocsize=16M.
>
> Jason
>
>
> On Mon, Sep 9, 2013 at 1:47 PM, Jay Kreps <ja...@gmail.com> wrote:
>
> > This could certainly be done. It would be slightly involved since you
> would
> > need to implement some kind of file-handle cache for both indexes and log
> > files and re-open them on demand when a read occurs. If someone wants to
> > take a shot at this, the first step would be to get a design wiki in
> place
> > on how this would work. This is potentially nice to reduce the open file
> > count (though open files are pretty cheap).
> >
> > That said this issue only impacts xfs and it seems to be fixed by that
> > setting jonathan found. I wonder if you could give that a try and see if
> it
> > works for you too? I feel dealing with closed files does add a lot of
> > complexity so if there is an easy fix I would probably rather avoid it.
> >
> > -Jay
> >
> >
> > On Mon, Sep 9, 2013 at 8:17 AM, Mike Heffner <mi...@librato.com> wrote:
> >
> > > We are also seeing this problem with version 0.7.1 and logs on an XFS
> > > partition. At our largest scale we can frequently free over 600GB of
> disk
> > > usage by simply restarting Kafka. We've examined the `lsof` output from
> > the
> > > Kafka process and while it does appear to have FDs open for all log
> files
> > > on disk (even those long past read from), it does not have any files
> open
> > > that were previously deleted from disk.
> > >
> > > Du output agrees that the seen size is much larger than apparent-size
> > size:
> > >
> > > root@kafkanode-1:/raid0/kafka-logs/measures-0# du -h
> > > 00000000242666442619.kafka
> > > 1.1G 00000000242666442619.kafka
> > > root@kafkanode-1:/raid0/kafka-logs/measures-0# du -h --apparent-size
> > > 00000000242666442619.kafka
> > > 513M 00000000242666442619.kafka
> > >
> > >
> > > Our log size/retention policy is:
> > >
> > > log.file.size=536870912
> > > log.retention.hours=96
> > >
> > > We tried dropping the caches from the Stack Overflow suggestion (sync;
> > echo
> > > 3 > /proc/sys/vm/drop_caches) but that didn't seem to clear up the
> extra
> > > space. Haven't had the chance to try remounting with the allocsize
> > option.
> > >
> > > In summary, it would be great if Kafka would close FD's to log files
> that
> > > hadn't been read from for some period of time if it addresses this
> issue.
> > >
> > > Cheers,
> > >
> > > Mike
> > >
> > > On Fri, Jul 26, 2013 at 5:03 PM, Jay Kreps <ja...@gmail.com>
> wrote:
> > >
> > > > Cool, good to know.
> > > >
> > > >
> > > > On Fri, Jul 26, 2013 at 2:00 PM, Jason Rosenberg <jb...@squareup.com>
> > > wrote:
> > > >
> > > > > Jay,
> > > > >
> > > > > My only experience so far with this is using XFS. It appears the
> XFS
> > > > > behavior is evolving, and in fact, we see somewhat different
> behavior
> > > > from
> > > > > 2 of our CentOS kernel versions in use. I've been trying to ask
> > > > questions
> > > > > about all this on the XFS.org mailing list, but so far, having not
> > much
> > > > > luck understanding the xfs versioning correlated to CentOS
> versions.
> > > > >
> > > > > Anyway, yes, I think it would definitely be worth trying the
> solution
> > > you
> > > > > suggest, which would be to close the file on rotation, and re-open
> > > > > read-only. Or to close files after a few hours of not being
> > accessed.
> > > > If
> > > > > a patch for one of these approaches can be cobbled together, I'd
> love
> > > to
> > > > > test it out on our staging environment. I'd be willing to
> experiment
> > > > with
> > > > > such a patch myself, although I'm not 100% of all the places to
> look
> > > (but
> > > > > might dive in).
> > > > >
> > > > > Xfs appears to the option of using dynamic, speculative
> > preallocation,
> > > in
> > > > > which case it progressively doubles the amount of space reserved
> for
> > a
> > > > > file, as the file grows. It does do this for all open files. If
> the
> > > > file
> > > > > is closed, it will then release the preallocated space not in use.
> > > It's
> > > > > not clear whether this releasing of space happens immediately on
> > close,
> > > > and
> > > > > whether re-opening the file read-only immediately, will keep it
> from
> > > > > releasing space (still trying to gather more info on that).
> > > > >
> > > > > I haven't looked too much at the index files, but those too appear
> to
> > > > have
> > > > > this behavior (e.g. preallocated size is always on the order of
> > double
> > > > the
> > > > > actual size, until the app is restarted).
> > > > >
> > > > > Jason
> > > > >
> > > > >
> > > > > On Fri, Jul 26, 2013 at 12:46 PM, Jay Kreps <ja...@gmail.com>
> > > wrote:
> > > > >
> > > > > > Interesting.
> > > > > >
> > > > > > Yes, Kafka keeps all log files open indefinitely. There is no
> > > inherent
> > > > > > reason this needs to be the case, though, it would be possible to
> > LRU
> > > > out
> > > > > > old file descriptors and close them if they are not accessed for
> a
> > > few
> > > > > > hours and then reopen on the first access. We just haven't
> > > implemented
> > > > > > anything like that.
> > > > > >
> > > > > > It would be good to understand this a little better. Does xfs
> > > > > pre-allocate
> > > > > > space for all open files? Perhaps just closing the file on log
> role
> > > and
> > > > > > opening it read-only would solve the issue? Is this at all
> related
> > to
> > > > the
> > > > > > use of sparse files for the indexes (i.e.
> > > > > RandomAccessFile.setLength(10MB)
> > > > > > when we create the index)? Does this effect other filesystems or
> > just
> > > > > xfs?
> > > > > >
> > > > > > -Jay
> > > > > >
> > > > > >
> > > > > > On Fri, Jul 26, 2013 at 12:42 AM, Jason Rosenberg <
> > jbr@squareup.com>
> > > > > > wrote:
> > > > > >
> > > > > > > It looks like xfs will reclaim the preallocated space for a
> file,
> > > > after
> > > > > > it
> > > > > > > is closed.
> > > > > > >
> > > > > > > Does kafka close a file after it has reached it's max size and
> > > > started
> > > > > > > writing to the next log file in sequence? Or does it keep all
> > open
> > > > > until
> > > > > > > they are deleted, or the server quits (that's what it seems
> > like).
> > > > > > >
> > > > > > > I could imagine that it might need to keep log files open, in
> > order
> > > > to
> > > > > > > allow consumers access to them. But does it keep them open
> > > > > indefinitely,
> > > > > > > after there is no longer any data to be written to them, and no
> > > > > consumers
> > > > > > > are currently attempting to read from them?
> > > > > > >
> > > > > > > Jason
> > > > > > >
> > > > > > >
> > > > > > > On Tue, Jul 16, 2013 at 4:32 PM, Jay Kreps <
> jay.kreps@gmail.com>
> > > > > wrote:
> > > > > > >
> > > > > > > > Interesting. Yes it will respect whatever setting it is given
> > for
> > > > new
> > > > > > > > segments created from that point on.
> > > > > > > >
> > > > > > > > -Jay
> > > > > > > >
> > > > > > > >
> > > > > > > > On Tue, Jul 16, 2013 at 11:23 AM, Jason Rosenberg <
> > > > jbr@squareup.com>
> > > > > > > > wrote:
> > > > > > > >
> > > > > > > > > Ok,
> > > > > > > > >
> > > > > > > > > An update on this. It seems we are using XFS, which is
> > > available
> > > > > in
> > > > > > > > newer
> > > > > > > > > versions of Centos. It definitely does pre-allocate space
> > as a
> > > > > file
> > > > > > > > grows,
> > > > > > > > > see:
> > > > > > > > >
> > > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> http://serverfault.com/questions/406069/why-are-my-xfs-filesystems-suddenly-consuming-more-space-and-full-of-sparse-file
> > > > > > > > >
> > > > > > > > > Apparently it's not hard-allocated space, and would be
> > released
> > > > > under
> > > > > > > > > resource pressure....seems we may need to update how we
> > monitor
> > > > > disk
> > > > > > > > space
> > > > > > > > > usage, etc....
> > > > > > > > >
> > > > > > > > > But, it seems that the default log file size of 1.1Gb,
> causes
> > > it
> > > > to
> > > > > > > jump
> > > > > > > > to
> > > > > > > > > preallocate an extra Gb. So, in theory, if I set a
> > strategic
> > > > log
> > > > > > file
> > > > > > > > > size to be just under the threshold that forces it to
> > > > exponentially
> > > > > > > > double
> > > > > > > > > the size from 1Gb to 2Gb, I should be able to mostly solve
> > this
> > > > > > issue.
> > > > > > > > > E.g. use 950Mb instead of 1.1Gb max log file size.
> > > > > > > > >
> > > > > > > > > If I change the max log file size for a broker, and restart
> > it,
> > > > > will
> > > > > > it
> > > > > > > > > respect the new size going forward?
> > > > > > > > >
> > > > > > > > > Jason
> > > > > > > > >
> > > > > > > > >
> > > > > > > > > On Sun, Jul 14, 2013 at 9:44 AM, Jay Kreps <
> > > jay.kreps@gmail.com>
> > > > > > > wrote:
> > > > > > > > >
> > > > > > > > > > Hey Jason,
> > > > > > > > > >
> > > > > > > > > > As Jun says, we haven't seen that issue and no one else
> has
> > > > > > reported
> > > > > > > > that
> > > > > > > > > > but it sounds like a bug of some kind.
> > > > > > > > > >
> > > > > > > > > > In 0.7 we don't do any preallocation of anything. The
> only
> > > time
> > > > > > files
> > > > > > > > > > shrink is during recovery--we re-checksum all messages
> that
> > > may
> > > > > not
> > > > > > > > have
> > > > > > > > > > been flushed and if any invalid messages are found we
> > > truncate
> > > > > them
> > > > > > > > off.
> > > > > > > > > > This would only occur after an unclean shutdown (kill -9)
> > and
> > > > you
> > > > > > > would
> > > > > > > > > get
> > > > > > > > > > a bunch of errors in log warning you this was happening.
> > > > > > > > > >
> > > > > > > > > > -Jay
> > > > > > > > > >
> > > > > > > > > >
> > > > > > > > > >
> > > > > > > > > > On Sun, Jul 14, 2013 at 1:36 AM, Jason Rosenberg <
> > > > > jbr@squareup.com
> > > > > > >
> > > > > > > > > wrote:
> > > > > > > > > >
> > > > > > > > > > > An update on this. It appears that the phenomenon I'm
> > > seeing
> > > > > is
> > > > > > > that
> > > > > > > > > > disk
> > > > > > > > > > > space is freed on restart, but it's not due files
> getting
> > > > > deleted
> > > > > > > on
> > > > > > > > > > > restart, but instead files are getting truncated on
> > > restart.
> > > > > It
> > > > > > > > > appears
> > > > > > > > > > > that log files get pre-allocated to a larger size than
> is
> > > > used
> > > > > > > right
> > > > > > > > > > away.
> > > > > > > > > > > Upon restart, they get truncated to the size of the
> file
> > > > that
> > > > > > > > actually
> > > > > > > > > > > contains data. Does this make sense?
> > > > > > > > > > >
> > > > > > > > > > > Before restart, I see a large number of log files size
> > > 2.1Gb.
> > > > > > Upon
> > > > > > > > > > > restart, the disk space reclaimed drops to almost half
> > > that,
> > > > on
> > > > > > > > > average.
> > > > > > > > > > >
> > > > > > > > > > > Thoughts?
> > > > > > > > > > >
> > > > > > > > > > > Jason
> > > > > > > > > > >
> > > > > > > > > > >
> > > > > > > > > > > On Thu, May 23, 2013 at 8:55 PM, Jun Rao <
> > junrao@gmail.com
> > > >
> > > > > > wrote:
> > > > > > > > > > >
> > > > > > > > > > > > I haven't seen this issue before. We do have ~1K
> topics
> > > in
> > > > > one
> > > > > > of
> > > > > > > > the
> > > > > > > > > > > Kafka
> > > > > > > > > > > > clusters at LinkedIn.
> > > > > > > > > > > >
> > > > > > > > > > > > Thanks,
> > > > > > > > > > > >
> > > > > > > > > > > > Jun
> > > > > > > > > > > >
> > > > > > > > > > > >
> > > > > > > > > > > > On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <
> > > > > > > > jbr@squareup.com>
> > > > > > > > > > > > wrote:
> > > > > > > > > > > >
> > > > > > > > > > > > > Yeah, that's what it looks like to me (looking at
> the
> > > > > code).
> > > > > > > So,
> > > > > > > > > I'm
> > > > > > > > > > > > > guessing it's some os level caching, resource
> > > recycling.
> > > > > > Have
> > > > > > > > you
> > > > > > > > > > ever
> > > > > > > > > > > > > heard of this happening? One thing that might be
> > > > different
> > > > > > in
> > > > > > > my
> > > > > > > > > > usage
> > > > > > > > > > > > > from the norm is a relatively large number of
> topics
> > > > (e.g.
> > > > > > ~2K
> > > > > > > > > > topics).
> > > > > > > > > > > > >
> > > > > > > > > > > > > Jason
> > > > > > > > > > > > >
> > > > > > > > > > > > >
> > > > > > > > > > > > > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <
> > > > junrao@gmail.com
> > > > > >
> > > > > > > > wrote:
> > > > > > > > > > > > >
> > > > > > > > > > > > > > Jason,
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > Kafka closes the handler of all delete files.
> > > > Otherwise,
> > > > > > the
> > > > > > > > > broker
> > > > > > > > > > > > will
> > > > > > > > > > > > > > run out of file handler quickly.
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > Thanks,
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > Jun
> > > > > > > > > > > > > >
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > On Wed, May 22, 2013 at 10:17 PM, Jason
> Rosenberg <
> > > > > > > > > > jbr@squareup.com>
> > > > > > > > > > > > > > wrote:
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > > So, does this indicate kafka (or the jvm
> itself)
> > is
> > > > not
> > > > > > > > > > > aggressively
> > > > > > > > > > > > > > > closing file handles of deleted files? Is
> there
> > a
> > > > fix
> > > > > > for
> > > > > > > > > this?
> > > > > > > > > > > Or
> > > > > > > > > > > > is
> > > > > > > > > > > > > > > there not likely anything to be done? What
> > happens
> > > > if
> > > > > > the
> > > > > > > > disk
> > > > > > > > > > > fills
> > > > > > > > > > > > > up
> > > > > > > > > > > > > > > with file handles for phantom deleted files?
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > Jason
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan
> Creasy
> > <
> > > > > > > jc@box.com
> > > > > > > > >
> > > > > > > > > > > wrote:
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > > It isn't uncommon if a process has an open
> file
> > > > > handle
> > > > > > > on a
> > > > > > > > > > file
> > > > > > > > > > > > that
> > > > > > > > > > > > > > is
> > > > > > > > > > > > > > > > deleted, the space is not freed until the
> > handle
> > > is
> > > > > > > closed.
> > > > > > > > > So
> > > > > > > > > > > > > > restarting
> > > > > > > > > > > > > > > > the process that has a handle on the file
> would
> > > > cause
> > > > > > the
> > > > > > > > > space
> > > > > > > > > > > to
> > > > > > > > > > > > be
> > > > > > > > > > > > > > > freed
> > > > > > > > > > > > > > > > also.
> > > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > > You can troubleshoot that with lsof.
> > > > > > > > > > > > > > > > Normally, I see 2-4 log segments deleted
> every
> > > hour
> > > > > in
> > > > > > my
> > > > > > > > > > > brokers.
> > > > > > > > > > > > I
> > > > > > > > > > > > > > see
> > > > > > > > > > > > > > > > log lines like this:
> > > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > > 2013-05-23 04:40:06,857 INFO
> > > [kafka-logcleaner-0]
> > > > > > > > > > > log.LogManager -
> > > > > > > > > > > > > > > > Deleting log segment
> 00000000035434043157.kafka
> > > > from
> > > > > > > > > <redacted
> > > > > > > > > > > > topic>
> > > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > > However, it seems like if I restart the
> > broker, a
> > > > > > massive
> > > > > > > > > > amount
> > > > > > > > > > > of
> > > > > > > > > > > > > > disk
> > > > > > > > > > > > > > > > space is freed (without a corresponding flood
> > of
> > > > > these
> > > > > > > log
> > > > > > > > > > > segment
> > > > > > > > > > > > > > > deleted
> > > > > > > > > > > > > > > > messages). Is there an explanation for this?
> > > Does
> > > > > > kafka
> > > > > > > > > keep
> > > > > > > > > > > > > > reference
> > > > > > > > > > > > > > > to
> > > > > > > > > > > > > > > > file segments around, and reuse them as
> needed
> > or
> > > > > > > > something?
> > > > > > > > > > And
> > > > > > > > > > > > > then
> > > > > > > > > > > > > > or
> > > > > > > > > > > > > > > > restart, the references to those free segment
> > > files
> > > > > are
> > > > > > > > > > dropped?
> > > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > > Thoughts?
> > > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > > This is with 0.7.2.
> > > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > > Jason
> > > > > > > > > > > > > > > >
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > >
> > > > > > > > > > > > >
> > > > > > > > > > > >
> > > > > > > > > > >
> > > > > > > > > >
> > > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> > >
> > >
> > > --
> > >
> > > Mike Heffner <mi...@librato.com>
> > > Librato, Inc.
> > >
> >
>
--
Mike Heffner <mi...@librato.com>
Librato, Inc.
Re: large amount of disk space freed on restart
Posted by Jason Rosenberg <jb...@squareup.com>.
Sorry, I forgot to close the loop on my experiences with this....
We solved this issue by setting the 'allocsize' mount option, in the fstab.
E.g. allocsize=16M.
Jason
On Mon, Sep 9, 2013 at 1:47 PM, Jay Kreps <ja...@gmail.com> wrote:
> This could certainly be done. It would be slightly involved since you would
> need to implement some kind of file-handle cache for both indexes and log
> files and re-open them on demand when a read occurs. If someone wants to
> take a shot at this, the first step would be to get a design wiki in place
> on how this would work. This is potentially nice to reduce the open file
> count (though open files are pretty cheap).
>
> That said this issue only impacts xfs and it seems to be fixed by that
> setting jonathan found. I wonder if you could give that a try and see if it
> works for you too? I feel dealing with closed files does add a lot of
> complexity so if there is an easy fix I would probably rather avoid it.
>
> -Jay
>
>
> On Mon, Sep 9, 2013 at 8:17 AM, Mike Heffner <mi...@librato.com> wrote:
>
> > We are also seeing this problem with version 0.7.1 and logs on an XFS
> > partition. At our largest scale we can frequently free over 600GB of disk
> > usage by simply restarting Kafka. We've examined the `lsof` output from
> the
> > Kafka process and while it does appear to have FDs open for all log files
> > on disk (even those long past read from), it does not have any files open
> > that were previously deleted from disk.
> >
> > Du output agrees that the seen size is much larger than apparent-size
> size:
> >
> > root@kafkanode-1:/raid0/kafka-logs/measures-0# du -h
> > 00000000242666442619.kafka
> > 1.1G 00000000242666442619.kafka
> > root@kafkanode-1:/raid0/kafka-logs/measures-0# du -h --apparent-size
> > 00000000242666442619.kafka
> > 513M 00000000242666442619.kafka
> >
> >
> > Our log size/retention policy is:
> >
> > log.file.size=536870912
> > log.retention.hours=96
> >
> > We tried dropping the caches from the Stack Overflow suggestion (sync;
> echo
> > 3 > /proc/sys/vm/drop_caches) but that didn't seem to clear up the extra
> > space. Haven't had the chance to try remounting with the allocsize
> option.
> >
> > In summary, it would be great if Kafka would close FD's to log files that
> > hadn't been read from for some period of time if it addresses this issue.
> >
> > Cheers,
> >
> > Mike
> >
> > On Fri, Jul 26, 2013 at 5:03 PM, Jay Kreps <ja...@gmail.com> wrote:
> >
> > > Cool, good to know.
> > >
> > >
> > > On Fri, Jul 26, 2013 at 2:00 PM, Jason Rosenberg <jb...@squareup.com>
> > wrote:
> > >
> > > > Jay,
> > > >
> > > > My only experience so far with this is using XFS. It appears the XFS
> > > > behavior is evolving, and in fact, we see somewhat different behavior
> > > from
> > > > 2 of our CentOS kernel versions in use. I've been trying to ask
> > > questions
> > > > about all this on the XFS.org mailing list, but so far, having not
> much
> > > > luck understanding the xfs versioning correlated to CentOS versions.
> > > >
> > > > Anyway, yes, I think it would definitely be worth trying the solution
> > you
> > > > suggest, which would be to close the file on rotation, and re-open
> > > > read-only. Or to close files after a few hours of not being
> accessed.
> > > If
> > > > a patch for one of these approaches can be cobbled together, I'd love
> > to
> > > > test it out on our staging environment. I'd be willing to experiment
> > > with
> > > > such a patch myself, although I'm not 100% of all the places to look
> > (but
> > > > might dive in).
> > > >
> > > > Xfs appears to the option of using dynamic, speculative
> preallocation,
> > in
> > > > which case it progressively doubles the amount of space reserved for
> a
> > > > file, as the file grows. It does do this for all open files. If the
> > > file
> > > > is closed, it will then release the preallocated space not in use.
> > It's
> > > > not clear whether this releasing of space happens immediately on
> close,
> > > and
> > > > whether re-opening the file read-only immediately, will keep it from
> > > > releasing space (still trying to gather more info on that).
> > > >
> > > > I haven't looked too much at the index files, but those too appear to
> > > have
> > > > this behavior (e.g. preallocated size is always on the order of
> double
> > > the
> > > > actual size, until the app is restarted).
> > > >
> > > > Jason
> > > >
> > > >
> > > > On Fri, Jul 26, 2013 at 12:46 PM, Jay Kreps <ja...@gmail.com>
> > wrote:
> > > >
> > > > > Interesting.
> > > > >
> > > > > Yes, Kafka keeps all log files open indefinitely. There is no
> > inherent
> > > > > reason this needs to be the case, though, it would be possible to
> LRU
> > > out
> > > > > old file descriptors and close them if they are not accessed for a
> > few
> > > > > hours and then reopen on the first access. We just haven't
> > implemented
> > > > > anything like that.
> > > > >
> > > > > It would be good to understand this a little better. Does xfs
> > > > pre-allocate
> > > > > space for all open files? Perhaps just closing the file on log role
> > and
> > > > > opening it read-only would solve the issue? Is this at all related
> to
> > > the
> > > > > use of sparse files for the indexes (i.e.
> > > > RandomAccessFile.setLength(10MB)
> > > > > when we create the index)? Does this effect other filesystems or
> just
> > > > xfs?
> > > > >
> > > > > -Jay
> > > > >
> > > > >
> > > > > On Fri, Jul 26, 2013 at 12:42 AM, Jason Rosenberg <
> jbr@squareup.com>
> > > > > wrote:
> > > > >
> > > > > > It looks like xfs will reclaim the preallocated space for a file,
> > > after
> > > > > it
> > > > > > is closed.
> > > > > >
> > > > > > Does kafka close a file after it has reached it's max size and
> > > started
> > > > > > writing to the next log file in sequence? Or does it keep all
> open
> > > > until
> > > > > > they are deleted, or the server quits (that's what it seems
> like).
> > > > > >
> > > > > > I could imagine that it might need to keep log files open, in
> order
> > > to
> > > > > > allow consumers access to them. But does it keep them open
> > > > indefinitely,
> > > > > > after there is no longer any data to be written to them, and no
> > > > consumers
> > > > > > are currently attempting to read from them?
> > > > > >
> > > > > > Jason
> > > > > >
> > > > > >
> > > > > > On Tue, Jul 16, 2013 at 4:32 PM, Jay Kreps <ja...@gmail.com>
> > > > wrote:
> > > > > >
> > > > > > > Interesting. Yes it will respect whatever setting it is given
> for
> > > new
> > > > > > > segments created from that point on.
> > > > > > >
> > > > > > > -Jay
> > > > > > >
> > > > > > >
> > > > > > > On Tue, Jul 16, 2013 at 11:23 AM, Jason Rosenberg <
> > > jbr@squareup.com>
> > > > > > > wrote:
> > > > > > >
> > > > > > > > Ok,
> > > > > > > >
> > > > > > > > An update on this. It seems we are using XFS, which is
> > available
> > > > in
> > > > > > > newer
> > > > > > > > versions of Centos. It definitely does pre-allocate space
> as a
> > > > file
> > > > > > > grows,
> > > > > > > > see:
> > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> http://serverfault.com/questions/406069/why-are-my-xfs-filesystems-suddenly-consuming-more-space-and-full-of-sparse-file
> > > > > > > >
> > > > > > > > Apparently it's not hard-allocated space, and would be
> released
> > > > under
> > > > > > > > resource pressure....seems we may need to update how we
> monitor
> > > > disk
> > > > > > > space
> > > > > > > > usage, etc....
> > > > > > > >
> > > > > > > > But, it seems that the default log file size of 1.1Gb, causes
> > it
> > > to
> > > > > > jump
> > > > > > > to
> > > > > > > > preallocate an extra Gb. So, in theory, if I set a
> strategic
> > > log
> > > > > file
> > > > > > > > size to be just under the threshold that forces it to
> > > exponentially
> > > > > > > double
> > > > > > > > the size from 1Gb to 2Gb, I should be able to mostly solve
> this
> > > > > issue.
> > > > > > > > E.g. use 950Mb instead of 1.1Gb max log file size.
> > > > > > > >
> > > > > > > > If I change the max log file size for a broker, and restart
> it,
> > > > will
> > > > > it
> > > > > > > > respect the new size going forward?
> > > > > > > >
> > > > > > > > Jason
> > > > > > > >
> > > > > > > >
> > > > > > > > On Sun, Jul 14, 2013 at 9:44 AM, Jay Kreps <
> > jay.kreps@gmail.com>
> > > > > > wrote:
> > > > > > > >
> > > > > > > > > Hey Jason,
> > > > > > > > >
> > > > > > > > > As Jun says, we haven't seen that issue and no one else has
> > > > > reported
> > > > > > > that
> > > > > > > > > but it sounds like a bug of some kind.
> > > > > > > > >
> > > > > > > > > In 0.7 we don't do any preallocation of anything. The only
> > time
> > > > > files
> > > > > > > > > shrink is during recovery--we re-checksum all messages that
> > may
> > > > not
> > > > > > > have
> > > > > > > > > been flushed and if any invalid messages are found we
> > truncate
> > > > them
> > > > > > > off.
> > > > > > > > > This would only occur after an unclean shutdown (kill -9)
> and
> > > you
> > > > > > would
> > > > > > > > get
> > > > > > > > > a bunch of errors in log warning you this was happening.
> > > > > > > > >
> > > > > > > > > -Jay
> > > > > > > > >
> > > > > > > > >
> > > > > > > > >
> > > > > > > > > On Sun, Jul 14, 2013 at 1:36 AM, Jason Rosenberg <
> > > > jbr@squareup.com
> > > > > >
> > > > > > > > wrote:
> > > > > > > > >
> > > > > > > > > > An update on this. It appears that the phenomenon I'm
> > seeing
> > > > is
> > > > > > that
> > > > > > > > > disk
> > > > > > > > > > space is freed on restart, but it's not due files getting
> > > > deleted
> > > > > > on
> > > > > > > > > > restart, but instead files are getting truncated on
> > restart.
> > > > It
> > > > > > > > appears
> > > > > > > > > > that log files get pre-allocated to a larger size than is
> > > used
> > > > > > right
> > > > > > > > > away.
> > > > > > > > > > Upon restart, they get truncated to the size of the file
> > > that
> > > > > > > actually
> > > > > > > > > > contains data. Does this make sense?
> > > > > > > > > >
> > > > > > > > > > Before restart, I see a large number of log files size
> > 2.1Gb.
> > > > > Upon
> > > > > > > > > > restart, the disk space reclaimed drops to almost half
> > that,
> > > on
> > > > > > > > average.
> > > > > > > > > >
> > > > > > > > > > Thoughts?
> > > > > > > > > >
> > > > > > > > > > Jason
> > > > > > > > > >
> > > > > > > > > >
> > > > > > > > > > On Thu, May 23, 2013 at 8:55 PM, Jun Rao <
> junrao@gmail.com
> > >
> > > > > wrote:
> > > > > > > > > >
> > > > > > > > > > > I haven't seen this issue before. We do have ~1K topics
> > in
> > > > one
> > > > > of
> > > > > > > the
> > > > > > > > > > Kafka
> > > > > > > > > > > clusters at LinkedIn.
> > > > > > > > > > >
> > > > > > > > > > > Thanks,
> > > > > > > > > > >
> > > > > > > > > > > Jun
> > > > > > > > > > >
> > > > > > > > > > >
> > > > > > > > > > > On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <
> > > > > > > jbr@squareup.com>
> > > > > > > > > > > wrote:
> > > > > > > > > > >
> > > > > > > > > > > > Yeah, that's what it looks like to me (looking at the
> > > > code).
> > > > > > So,
> > > > > > > > I'm
> > > > > > > > > > > > guessing it's some os level caching, resource
> > recycling.
> > > > > Have
> > > > > > > you
> > > > > > > > > ever
> > > > > > > > > > > > heard of this happening? One thing that might be
> > > different
> > > > > in
> > > > > > my
> > > > > > > > > usage
> > > > > > > > > > > > from the norm is a relatively large number of topics
> > > (e.g.
> > > > > ~2K
> > > > > > > > > topics).
> > > > > > > > > > > >
> > > > > > > > > > > > Jason
> > > > > > > > > > > >
> > > > > > > > > > > >
> > > > > > > > > > > > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <
> > > junrao@gmail.com
> > > > >
> > > > > > > wrote:
> > > > > > > > > > > >
> > > > > > > > > > > > > Jason,
> > > > > > > > > > > > >
> > > > > > > > > > > > > Kafka closes the handler of all delete files.
> > > Otherwise,
> > > > > the
> > > > > > > > broker
> > > > > > > > > > > will
> > > > > > > > > > > > > run out of file handler quickly.
> > > > > > > > > > > > >
> > > > > > > > > > > > > Thanks,
> > > > > > > > > > > > >
> > > > > > > > > > > > > Jun
> > > > > > > > > > > > >
> > > > > > > > > > > > >
> > > > > > > > > > > > > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <
> > > > > > > > > jbr@squareup.com>
> > > > > > > > > > > > > wrote:
> > > > > > > > > > > > >
> > > > > > > > > > > > > > So, does this indicate kafka (or the jvm itself)
> is
> > > not
> > > > > > > > > > aggressively
> > > > > > > > > > > > > > closing file handles of deleted files? Is there
> a
> > > fix
> > > > > for
> > > > > > > > this?
> > > > > > > > > > Or
> > > > > > > > > > > is
> > > > > > > > > > > > > > there not likely anything to be done? What
> happens
> > > if
> > > > > the
> > > > > > > disk
> > > > > > > > > > fills
> > > > > > > > > > > > up
> > > > > > > > > > > > > > with file handles for phantom deleted files?
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > Jason
> > > > > > > > > > > > > >
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy
> <
> > > > > > jc@box.com
> > > > > > > >
> > > > > > > > > > wrote:
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > > It isn't uncommon if a process has an open file
> > > > handle
> > > > > > on a
> > > > > > > > > file
> > > > > > > > > > > that
> > > > > > > > > > > > > is
> > > > > > > > > > > > > > > deleted, the space is not freed until the
> handle
> > is
> > > > > > closed.
> > > > > > > > So
> > > > > > > > > > > > > restarting
> > > > > > > > > > > > > > > the process that has a handle on the file would
> > > cause
> > > > > the
> > > > > > > > space
> > > > > > > > > > to
> > > > > > > > > > > be
> > > > > > > > > > > > > > freed
> > > > > > > > > > > > > > > also.
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > You can troubleshoot that with lsof.
> > > > > > > > > > > > > > > Normally, I see 2-4 log segments deleted every
> > hour
> > > > in
> > > > > my
> > > > > > > > > > brokers.
> > > > > > > > > > > I
> > > > > > > > > > > > > see
> > > > > > > > > > > > > > > log lines like this:
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > 2013-05-23 04:40:06,857 INFO
> > [kafka-logcleaner-0]
> > > > > > > > > > log.LogManager -
> > > > > > > > > > > > > > > Deleting log segment 00000000035434043157.kafka
> > > from
> > > > > > > > <redacted
> > > > > > > > > > > topic>
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > However, it seems like if I restart the
> broker, a
> > > > > massive
> > > > > > > > > amount
> > > > > > > > > > of
> > > > > > > > > > > > > disk
> > > > > > > > > > > > > > > space is freed (without a corresponding flood
> of
> > > > these
> > > > > > log
> > > > > > > > > > segment
> > > > > > > > > > > > > > deleted
> > > > > > > > > > > > > > > messages). Is there an explanation for this?
> > Does
> > > > > kafka
> > > > > > > > keep
> > > > > > > > > > > > > reference
> > > > > > > > > > > > > > to
> > > > > > > > > > > > > > > file segments around, and reuse them as needed
> or
> > > > > > > something?
> > > > > > > > > And
> > > > > > > > > > > > then
> > > > > > > > > > > > > or
> > > > > > > > > > > > > > > restart, the references to those free segment
> > files
> > > > are
> > > > > > > > > dropped?
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > Thoughts?
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > This is with 0.7.2.
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > > > Jason
> > > > > > > > > > > > > > >
> > > > > > > > > > > > > >
> > > > > > > > > > > > >
> > > > > > > > > > > >
> > > > > > > > > > >
> > > > > > > > > >
> > > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> >
> >
> > --
> >
> > Mike Heffner <mi...@librato.com>
> > Librato, Inc.
> >
>
Re: large amount of disk space freed on restart
Posted by Jay Kreps <ja...@gmail.com>.
This could certainly be done. It would be slightly involved since you would
need to implement some kind of file-handle cache for both indexes and log
files and re-open them on demand when a read occurs. If someone wants to
take a shot at this, the first step would be to get a design wiki in place
on how this would work. This is potentially nice to reduce the open file
count (though open files are pretty cheap).
That said this issue only impacts xfs and it seems to be fixed by that
setting jonathan found. I wonder if you could give that a try and see if it
works for you too? I feel dealing with closed files does add a lot of
complexity so if there is an easy fix I would probably rather avoid it.
-Jay
On Mon, Sep 9, 2013 at 8:17 AM, Mike Heffner <mi...@librato.com> wrote:
> We are also seeing this problem with version 0.7.1 and logs on an XFS
> partition. At our largest scale we can frequently free over 600GB of disk
> usage by simply restarting Kafka. We've examined the `lsof` output from the
> Kafka process and while it does appear to have FDs open for all log files
> on disk (even those long past read from), it does not have any files open
> that were previously deleted from disk.
>
> Du output agrees that the seen size is much larger than apparent-size size:
>
> root@kafkanode-1:/raid0/kafka-logs/measures-0# du -h
> 00000000242666442619.kafka
> 1.1G 00000000242666442619.kafka
> root@kafkanode-1:/raid0/kafka-logs/measures-0# du -h --apparent-size
> 00000000242666442619.kafka
> 513M 00000000242666442619.kafka
>
>
> Our log size/retention policy is:
>
> log.file.size=536870912
> log.retention.hours=96
>
> We tried dropping the caches from the Stack Overflow suggestion (sync; echo
> 3 > /proc/sys/vm/drop_caches) but that didn't seem to clear up the extra
> space. Haven't had the chance to try remounting with the allocsize option.
>
> In summary, it would be great if Kafka would close FD's to log files that
> hadn't been read from for some period of time if it addresses this issue.
>
> Cheers,
>
> Mike
>
> On Fri, Jul 26, 2013 at 5:03 PM, Jay Kreps <ja...@gmail.com> wrote:
>
> > Cool, good to know.
> >
> >
> > On Fri, Jul 26, 2013 at 2:00 PM, Jason Rosenberg <jb...@squareup.com>
> wrote:
> >
> > > Jay,
> > >
> > > My only experience so far with this is using XFS. It appears the XFS
> > > behavior is evolving, and in fact, we see somewhat different behavior
> > from
> > > 2 of our CentOS kernel versions in use. I've been trying to ask
> > questions
> > > about all this on the XFS.org mailing list, but so far, having not much
> > > luck understanding the xfs versioning correlated to CentOS versions.
> > >
> > > Anyway, yes, I think it would definitely be worth trying the solution
> you
> > > suggest, which would be to close the file on rotation, and re-open
> > > read-only. Or to close files after a few hours of not being accessed.
> > If
> > > a patch for one of these approaches can be cobbled together, I'd love
> to
> > > test it out on our staging environment. I'd be willing to experiment
> > with
> > > such a patch myself, although I'm not 100% of all the places to look
> (but
> > > might dive in).
> > >
> > > Xfs appears to the option of using dynamic, speculative preallocation,
> in
> > > which case it progressively doubles the amount of space reserved for a
> > > file, as the file grows. It does do this for all open files. If the
> > file
> > > is closed, it will then release the preallocated space not in use.
> It's
> > > not clear whether this releasing of space happens immediately on close,
> > and
> > > whether re-opening the file read-only immediately, will keep it from
> > > releasing space (still trying to gather more info on that).
> > >
> > > I haven't looked too much at the index files, but those too appear to
> > have
> > > this behavior (e.g. preallocated size is always on the order of double
> > the
> > > actual size, until the app is restarted).
> > >
> > > Jason
> > >
> > >
> > > On Fri, Jul 26, 2013 at 12:46 PM, Jay Kreps <ja...@gmail.com>
> wrote:
> > >
> > > > Interesting.
> > > >
> > > > Yes, Kafka keeps all log files open indefinitely. There is no
> inherent
> > > > reason this needs to be the case, though, it would be possible to LRU
> > out
> > > > old file descriptors and close them if they are not accessed for a
> few
> > > > hours and then reopen on the first access. We just haven't
> implemented
> > > > anything like that.
> > > >
> > > > It would be good to understand this a little better. Does xfs
> > > pre-allocate
> > > > space for all open files? Perhaps just closing the file on log role
> and
> > > > opening it read-only would solve the issue? Is this at all related to
> > the
> > > > use of sparse files for the indexes (i.e.
> > > RandomAccessFile.setLength(10MB)
> > > > when we create the index)? Does this effect other filesystems or just
> > > xfs?
> > > >
> > > > -Jay
> > > >
> > > >
> > > > On Fri, Jul 26, 2013 at 12:42 AM, Jason Rosenberg <jb...@squareup.com>
> > > > wrote:
> > > >
> > > > > It looks like xfs will reclaim the preallocated space for a file,
> > after
> > > > it
> > > > > is closed.
> > > > >
> > > > > Does kafka close a file after it has reached it's max size and
> > started
> > > > > writing to the next log file in sequence? Or does it keep all open
> > > until
> > > > > they are deleted, or the server quits (that's what it seems like).
> > > > >
> > > > > I could imagine that it might need to keep log files open, in order
> > to
> > > > > allow consumers access to them. But does it keep them open
> > > indefinitely,
> > > > > after there is no longer any data to be written to them, and no
> > > consumers
> > > > > are currently attempting to read from them?
> > > > >
> > > > > Jason
> > > > >
> > > > >
> > > > > On Tue, Jul 16, 2013 at 4:32 PM, Jay Kreps <ja...@gmail.com>
> > > wrote:
> > > > >
> > > > > > Interesting. Yes it will respect whatever setting it is given for
> > new
> > > > > > segments created from that point on.
> > > > > >
> > > > > > -Jay
> > > > > >
> > > > > >
> > > > > > On Tue, Jul 16, 2013 at 11:23 AM, Jason Rosenberg <
> > jbr@squareup.com>
> > > > > > wrote:
> > > > > >
> > > > > > > Ok,
> > > > > > >
> > > > > > > An update on this. It seems we are using XFS, which is
> available
> > > in
> > > > > > newer
> > > > > > > versions of Centos. It definitely does pre-allocate space as a
> > > file
> > > > > > grows,
> > > > > > > see:
> > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> http://serverfault.com/questions/406069/why-are-my-xfs-filesystems-suddenly-consuming-more-space-and-full-of-sparse-file
> > > > > > >
> > > > > > > Apparently it's not hard-allocated space, and would be released
> > > under
> > > > > > > resource pressure....seems we may need to update how we monitor
> > > disk
> > > > > > space
> > > > > > > usage, etc....
> > > > > > >
> > > > > > > But, it seems that the default log file size of 1.1Gb, causes
> it
> > to
> > > > > jump
> > > > > > to
> > > > > > > preallocate an extra Gb. So, in theory, if I set a strategic
> > log
> > > > file
> > > > > > > size to be just under the threshold that forces it to
> > exponentially
> > > > > > double
> > > > > > > the size from 1Gb to 2Gb, I should be able to mostly solve this
> > > > issue.
> > > > > > > E.g. use 950Mb instead of 1.1Gb max log file size.
> > > > > > >
> > > > > > > If I change the max log file size for a broker, and restart it,
> > > will
> > > > it
> > > > > > > respect the new size going forward?
> > > > > > >
> > > > > > > Jason
> > > > > > >
> > > > > > >
> > > > > > > On Sun, Jul 14, 2013 at 9:44 AM, Jay Kreps <
> jay.kreps@gmail.com>
> > > > > wrote:
> > > > > > >
> > > > > > > > Hey Jason,
> > > > > > > >
> > > > > > > > As Jun says, we haven't seen that issue and no one else has
> > > > reported
> > > > > > that
> > > > > > > > but it sounds like a bug of some kind.
> > > > > > > >
> > > > > > > > In 0.7 we don't do any preallocation of anything. The only
> time
> > > > files
> > > > > > > > shrink is during recovery--we re-checksum all messages that
> may
> > > not
> > > > > > have
> > > > > > > > been flushed and if any invalid messages are found we
> truncate
> > > them
> > > > > > off.
> > > > > > > > This would only occur after an unclean shutdown (kill -9) and
> > you
> > > > > would
> > > > > > > get
> > > > > > > > a bunch of errors in log warning you this was happening.
> > > > > > > >
> > > > > > > > -Jay
> > > > > > > >
> > > > > > > >
> > > > > > > >
> > > > > > > > On Sun, Jul 14, 2013 at 1:36 AM, Jason Rosenberg <
> > > jbr@squareup.com
> > > > >
> > > > > > > wrote:
> > > > > > > >
> > > > > > > > > An update on this. It appears that the phenomenon I'm
> seeing
> > > is
> > > > > that
> > > > > > > > disk
> > > > > > > > > space is freed on restart, but it's not due files getting
> > > deleted
> > > > > on
> > > > > > > > > restart, but instead files are getting truncated on
> restart.
> > > It
> > > > > > > appears
> > > > > > > > > that log files get pre-allocated to a larger size than is
> > used
> > > > > right
> > > > > > > > away.
> > > > > > > > > Upon restart, they get truncated to the size of the file
> > that
> > > > > > actually
> > > > > > > > > contains data. Does this make sense?
> > > > > > > > >
> > > > > > > > > Before restart, I see a large number of log files size
> 2.1Gb.
> > > > Upon
> > > > > > > > > restart, the disk space reclaimed drops to almost half
> that,
> > on
> > > > > > > average.
> > > > > > > > >
> > > > > > > > > Thoughts?
> > > > > > > > >
> > > > > > > > > Jason
> > > > > > > > >
> > > > > > > > >
> > > > > > > > > On Thu, May 23, 2013 at 8:55 PM, Jun Rao <junrao@gmail.com
> >
> > > > wrote:
> > > > > > > > >
> > > > > > > > > > I haven't seen this issue before. We do have ~1K topics
> in
> > > one
> > > > of
> > > > > > the
> > > > > > > > > Kafka
> > > > > > > > > > clusters at LinkedIn.
> > > > > > > > > >
> > > > > > > > > > Thanks,
> > > > > > > > > >
> > > > > > > > > > Jun
> > > > > > > > > >
> > > > > > > > > >
> > > > > > > > > > On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <
> > > > > > jbr@squareup.com>
> > > > > > > > > > wrote:
> > > > > > > > > >
> > > > > > > > > > > Yeah, that's what it looks like to me (looking at the
> > > code).
> > > > > So,
> > > > > > > I'm
> > > > > > > > > > > guessing it's some os level caching, resource
> recycling.
> > > > Have
> > > > > > you
> > > > > > > > ever
> > > > > > > > > > > heard of this happening? One thing that might be
> > different
> > > > in
> > > > > my
> > > > > > > > usage
> > > > > > > > > > > from the norm is a relatively large number of topics
> > (e.g.
> > > > ~2K
> > > > > > > > topics).
> > > > > > > > > > >
> > > > > > > > > > > Jason
> > > > > > > > > > >
> > > > > > > > > > >
> > > > > > > > > > > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <
> > junrao@gmail.com
> > > >
> > > > > > wrote:
> > > > > > > > > > >
> > > > > > > > > > > > Jason,
> > > > > > > > > > > >
> > > > > > > > > > > > Kafka closes the handler of all delete files.
> > Otherwise,
> > > > the
> > > > > > > broker
> > > > > > > > > > will
> > > > > > > > > > > > run out of file handler quickly.
> > > > > > > > > > > >
> > > > > > > > > > > > Thanks,
> > > > > > > > > > > >
> > > > > > > > > > > > Jun
> > > > > > > > > > > >
> > > > > > > > > > > >
> > > > > > > > > > > > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <
> > > > > > > > jbr@squareup.com>
> > > > > > > > > > > > wrote:
> > > > > > > > > > > >
> > > > > > > > > > > > > So, does this indicate kafka (or the jvm itself) is
> > not
> > > > > > > > > aggressively
> > > > > > > > > > > > > closing file handles of deleted files? Is there a
> > fix
> > > > for
> > > > > > > this?
> > > > > > > > > Or
> > > > > > > > > > is
> > > > > > > > > > > > > there not likely anything to be done? What happens
> > if
> > > > the
> > > > > > disk
> > > > > > > > > fills
> > > > > > > > > > > up
> > > > > > > > > > > > > with file handles for phantom deleted files?
> > > > > > > > > > > > >
> > > > > > > > > > > > > Jason
> > > > > > > > > > > > >
> > > > > > > > > > > > >
> > > > > > > > > > > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <
> > > > > jc@box.com
> > > > > > >
> > > > > > > > > wrote:
> > > > > > > > > > > > >
> > > > > > > > > > > > > > It isn't uncommon if a process has an open file
> > > handle
> > > > > on a
> > > > > > > > file
> > > > > > > > > > that
> > > > > > > > > > > > is
> > > > > > > > > > > > > > deleted, the space is not freed until the handle
> is
> > > > > closed.
> > > > > > > So
> > > > > > > > > > > > restarting
> > > > > > > > > > > > > > the process that has a handle on the file would
> > cause
> > > > the
> > > > > > > space
> > > > > > > > > to
> > > > > > > > > > be
> > > > > > > > > > > > > freed
> > > > > > > > > > > > > > also.
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > You can troubleshoot that with lsof.
> > > > > > > > > > > > > > Normally, I see 2-4 log segments deleted every
> hour
> > > in
> > > > my
> > > > > > > > > brokers.
> > > > > > > > > > I
> > > > > > > > > > > > see
> > > > > > > > > > > > > > log lines like this:
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > 2013-05-23 04:40:06,857 INFO
> [kafka-logcleaner-0]
> > > > > > > > > log.LogManager -
> > > > > > > > > > > > > > Deleting log segment 00000000035434043157.kafka
> > from
> > > > > > > <redacted
> > > > > > > > > > topic>
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > However, it seems like if I restart the broker, a
> > > > massive
> > > > > > > > amount
> > > > > > > > > of
> > > > > > > > > > > > disk
> > > > > > > > > > > > > > space is freed (without a corresponding flood of
> > > these
> > > > > log
> > > > > > > > > segment
> > > > > > > > > > > > > deleted
> > > > > > > > > > > > > > messages). Is there an explanation for this?
> Does
> > > > kafka
> > > > > > > keep
> > > > > > > > > > > > reference
> > > > > > > > > > > > > to
> > > > > > > > > > > > > > file segments around, and reuse them as needed or
> > > > > > something?
> > > > > > > > And
> > > > > > > > > > > then
> > > > > > > > > > > > or
> > > > > > > > > > > > > > restart, the references to those free segment
> files
> > > are
> > > > > > > > dropped?
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > Thoughts?
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > This is with 0.7.2.
> > > > > > > > > > > > > >
> > > > > > > > > > > > > > Jason
> > > > > > > > > > > > > >
> > > > > > > > > > > > >
> > > > > > > > > > > >
> > > > > > > > > > >
> > > > > > > > > >
> > > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
>
>
> --
>
> Mike Heffner <mi...@librato.com>
> Librato, Inc.
>
Re: large amount of disk space freed on restart
Posted by Mike Heffner <mi...@librato.com>.
We are also seeing this problem with version 0.7.1 and logs on an XFS
partition. At our largest scale we can frequently free over 600GB of disk
usage by simply restarting Kafka. We've examined the `lsof` output from the
Kafka process and while it does appear to have FDs open for all log files
on disk (even those long past read from), it does not have any files open
that were previously deleted from disk.
Du output agrees that the seen size is much larger than apparent-size size:
root@kafkanode-1:/raid0/kafka-logs/measures-0# du -h
00000000242666442619.kafka
1.1G 00000000242666442619.kafka
root@kafkanode-1:/raid0/kafka-logs/measures-0# du -h --apparent-size
00000000242666442619.kafka
513M 00000000242666442619.kafka
Our log size/retention policy is:
log.file.size=536870912
log.retention.hours=96
We tried dropping the caches from the Stack Overflow suggestion (sync; echo
3 > /proc/sys/vm/drop_caches) but that didn't seem to clear up the extra
space. Haven't had the chance to try remounting with the allocsize option.
In summary, it would be great if Kafka would close FD's to log files that
hadn't been read from for some period of time if it addresses this issue.
Cheers,
Mike
On Fri, Jul 26, 2013 at 5:03 PM, Jay Kreps <ja...@gmail.com> wrote:
> Cool, good to know.
>
>
> On Fri, Jul 26, 2013 at 2:00 PM, Jason Rosenberg <jb...@squareup.com> wrote:
>
> > Jay,
> >
> > My only experience so far with this is using XFS. It appears the XFS
> > behavior is evolving, and in fact, we see somewhat different behavior
> from
> > 2 of our CentOS kernel versions in use. I've been trying to ask
> questions
> > about all this on the XFS.org mailing list, but so far, having not much
> > luck understanding the xfs versioning correlated to CentOS versions.
> >
> > Anyway, yes, I think it would definitely be worth trying the solution you
> > suggest, which would be to close the file on rotation, and re-open
> > read-only. Or to close files after a few hours of not being accessed.
> If
> > a patch for one of these approaches can be cobbled together, I'd love to
> > test it out on our staging environment. I'd be willing to experiment
> with
> > such a patch myself, although I'm not 100% of all the places to look (but
> > might dive in).
> >
> > Xfs appears to the option of using dynamic, speculative preallocation, in
> > which case it progressively doubles the amount of space reserved for a
> > file, as the file grows. It does do this for all open files. If the
> file
> > is closed, it will then release the preallocated space not in use. It's
> > not clear whether this releasing of space happens immediately on close,
> and
> > whether re-opening the file read-only immediately, will keep it from
> > releasing space (still trying to gather more info on that).
> >
> > I haven't looked too much at the index files, but those too appear to
> have
> > this behavior (e.g. preallocated size is always on the order of double
> the
> > actual size, until the app is restarted).
> >
> > Jason
> >
> >
> > On Fri, Jul 26, 2013 at 12:46 PM, Jay Kreps <ja...@gmail.com> wrote:
> >
> > > Interesting.
> > >
> > > Yes, Kafka keeps all log files open indefinitely. There is no inherent
> > > reason this needs to be the case, though, it would be possible to LRU
> out
> > > old file descriptors and close them if they are not accessed for a few
> > > hours and then reopen on the first access. We just haven't implemented
> > > anything like that.
> > >
> > > It would be good to understand this a little better. Does xfs
> > pre-allocate
> > > space for all open files? Perhaps just closing the file on log role and
> > > opening it read-only would solve the issue? Is this at all related to
> the
> > > use of sparse files for the indexes (i.e.
> > RandomAccessFile.setLength(10MB)
> > > when we create the index)? Does this effect other filesystems or just
> > xfs?
> > >
> > > -Jay
> > >
> > >
> > > On Fri, Jul 26, 2013 at 12:42 AM, Jason Rosenberg <jb...@squareup.com>
> > > wrote:
> > >
> > > > It looks like xfs will reclaim the preallocated space for a file,
> after
> > > it
> > > > is closed.
> > > >
> > > > Does kafka close a file after it has reached it's max size and
> started
> > > > writing to the next log file in sequence? Or does it keep all open
> > until
> > > > they are deleted, or the server quits (that's what it seems like).
> > > >
> > > > I could imagine that it might need to keep log files open, in order
> to
> > > > allow consumers access to them. But does it keep them open
> > indefinitely,
> > > > after there is no longer any data to be written to them, and no
> > consumers
> > > > are currently attempting to read from them?
> > > >
> > > > Jason
> > > >
> > > >
> > > > On Tue, Jul 16, 2013 at 4:32 PM, Jay Kreps <ja...@gmail.com>
> > wrote:
> > > >
> > > > > Interesting. Yes it will respect whatever setting it is given for
> new
> > > > > segments created from that point on.
> > > > >
> > > > > -Jay
> > > > >
> > > > >
> > > > > On Tue, Jul 16, 2013 at 11:23 AM, Jason Rosenberg <
> jbr@squareup.com>
> > > > > wrote:
> > > > >
> > > > > > Ok,
> > > > > >
> > > > > > An update on this. It seems we are using XFS, which is available
> > in
> > > > > newer
> > > > > > versions of Centos. It definitely does pre-allocate space as a
> > file
> > > > > grows,
> > > > > > see:
> > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
> http://serverfault.com/questions/406069/why-are-my-xfs-filesystems-suddenly-consuming-more-space-and-full-of-sparse-file
> > > > > >
> > > > > > Apparently it's not hard-allocated space, and would be released
> > under
> > > > > > resource pressure....seems we may need to update how we monitor
> > disk
> > > > > space
> > > > > > usage, etc....
> > > > > >
> > > > > > But, it seems that the default log file size of 1.1Gb, causes it
> to
> > > > jump
> > > > > to
> > > > > > preallocate an extra Gb. So, in theory, if I set a strategic
> log
> > > file
> > > > > > size to be just under the threshold that forces it to
> exponentially
> > > > > double
> > > > > > the size from 1Gb to 2Gb, I should be able to mostly solve this
> > > issue.
> > > > > > E.g. use 950Mb instead of 1.1Gb max log file size.
> > > > > >
> > > > > > If I change the max log file size for a broker, and restart it,
> > will
> > > it
> > > > > > respect the new size going forward?
> > > > > >
> > > > > > Jason
> > > > > >
> > > > > >
> > > > > > On Sun, Jul 14, 2013 at 9:44 AM, Jay Kreps <ja...@gmail.com>
> > > > wrote:
> > > > > >
> > > > > > > Hey Jason,
> > > > > > >
> > > > > > > As Jun says, we haven't seen that issue and no one else has
> > > reported
> > > > > that
> > > > > > > but it sounds like a bug of some kind.
> > > > > > >
> > > > > > > In 0.7 we don't do any preallocation of anything. The only time
> > > files
> > > > > > > shrink is during recovery--we re-checksum all messages that may
> > not
> > > > > have
> > > > > > > been flushed and if any invalid messages are found we truncate
> > them
> > > > > off.
> > > > > > > This would only occur after an unclean shutdown (kill -9) and
> you
> > > > would
> > > > > > get
> > > > > > > a bunch of errors in log warning you this was happening.
> > > > > > >
> > > > > > > -Jay
> > > > > > >
> > > > > > >
> > > > > > >
> > > > > > > On Sun, Jul 14, 2013 at 1:36 AM, Jason Rosenberg <
> > jbr@squareup.com
> > > >
> > > > > > wrote:
> > > > > > >
> > > > > > > > An update on this. It appears that the phenomenon I'm seeing
> > is
> > > > that
> > > > > > > disk
> > > > > > > > space is freed on restart, but it's not due files getting
> > deleted
> > > > on
> > > > > > > > restart, but instead files are getting truncated on restart.
> > It
> > > > > > appears
> > > > > > > > that log files get pre-allocated to a larger size than is
> used
> > > > right
> > > > > > > away.
> > > > > > > > Upon restart, they get truncated to the size of the file
> that
> > > > > actually
> > > > > > > > contains data. Does this make sense?
> > > > > > > >
> > > > > > > > Before restart, I see a large number of log files size 2.1Gb.
> > > Upon
> > > > > > > > restart, the disk space reclaimed drops to almost half that,
> on
> > > > > > average.
> > > > > > > >
> > > > > > > > Thoughts?
> > > > > > > >
> > > > > > > > Jason
> > > > > > > >
> > > > > > > >
> > > > > > > > On Thu, May 23, 2013 at 8:55 PM, Jun Rao <ju...@gmail.com>
> > > wrote:
> > > > > > > >
> > > > > > > > > I haven't seen this issue before. We do have ~1K topics in
> > one
> > > of
> > > > > the
> > > > > > > > Kafka
> > > > > > > > > clusters at LinkedIn.
> > > > > > > > >
> > > > > > > > > Thanks,
> > > > > > > > >
> > > > > > > > > Jun
> > > > > > > > >
> > > > > > > > >
> > > > > > > > > On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <
> > > > > jbr@squareup.com>
> > > > > > > > > wrote:
> > > > > > > > >
> > > > > > > > > > Yeah, that's what it looks like to me (looking at the
> > code).
> > > > So,
> > > > > > I'm
> > > > > > > > > > guessing it's some os level caching, resource recycling.
> > > Have
> > > > > you
> > > > > > > ever
> > > > > > > > > > heard of this happening? One thing that might be
> different
> > > in
> > > > my
> > > > > > > usage
> > > > > > > > > > from the norm is a relatively large number of topics
> (e.g.
> > > ~2K
> > > > > > > topics).
> > > > > > > > > >
> > > > > > > > > > Jason
> > > > > > > > > >
> > > > > > > > > >
> > > > > > > > > > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <
> junrao@gmail.com
> > >
> > > > > wrote:
> > > > > > > > > >
> > > > > > > > > > > Jason,
> > > > > > > > > > >
> > > > > > > > > > > Kafka closes the handler of all delete files.
> Otherwise,
> > > the
> > > > > > broker
> > > > > > > > > will
> > > > > > > > > > > run out of file handler quickly.
> > > > > > > > > > >
> > > > > > > > > > > Thanks,
> > > > > > > > > > >
> > > > > > > > > > > Jun
> > > > > > > > > > >
> > > > > > > > > > >
> > > > > > > > > > > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <
> > > > > > > jbr@squareup.com>
> > > > > > > > > > > wrote:
> > > > > > > > > > >
> > > > > > > > > > > > So, does this indicate kafka (or the jvm itself) is
> not
> > > > > > > > aggressively
> > > > > > > > > > > > closing file handles of deleted files? Is there a
> fix
> > > for
> > > > > > this?
> > > > > > > > Or
> > > > > > > > > is
> > > > > > > > > > > > there not likely anything to be done? What happens
> if
> > > the
> > > > > disk
> > > > > > > > fills
> > > > > > > > > > up
> > > > > > > > > > > > with file handles for phantom deleted files?
> > > > > > > > > > > >
> > > > > > > > > > > > Jason
> > > > > > > > > > > >
> > > > > > > > > > > >
> > > > > > > > > > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <
> > > > jc@box.com
> > > > > >
> > > > > > > > wrote:
> > > > > > > > > > > >
> > > > > > > > > > > > > It isn't uncommon if a process has an open file
> > handle
> > > > on a
> > > > > > > file
> > > > > > > > > that
> > > > > > > > > > > is
> > > > > > > > > > > > > deleted, the space is not freed until the handle is
> > > > closed.
> > > > > > So
> > > > > > > > > > > restarting
> > > > > > > > > > > > > the process that has a handle on the file would
> cause
> > > the
> > > > > > space
> > > > > > > > to
> > > > > > > > > be
> > > > > > > > > > > > freed
> > > > > > > > > > > > > also.
> > > > > > > > > > > > >
> > > > > > > > > > > > > You can troubleshoot that with lsof.
> > > > > > > > > > > > > Normally, I see 2-4 log segments deleted every hour
> > in
> > > my
> > > > > > > > brokers.
> > > > > > > > > I
> > > > > > > > > > > see
> > > > > > > > > > > > > log lines like this:
> > > > > > > > > > > > >
> > > > > > > > > > > > > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0]
> > > > > > > > log.LogManager -
> > > > > > > > > > > > > Deleting log segment 00000000035434043157.kafka
> from
> > > > > > <redacted
> > > > > > > > > topic>
> > > > > > > > > > > > >
> > > > > > > > > > > > > However, it seems like if I restart the broker, a
> > > massive
> > > > > > > amount
> > > > > > > > of
> > > > > > > > > > > disk
> > > > > > > > > > > > > space is freed (without a corresponding flood of
> > these
> > > > log
> > > > > > > > segment
> > > > > > > > > > > > deleted
> > > > > > > > > > > > > messages). Is there an explanation for this? Does
> > > kafka
> > > > > > keep
> > > > > > > > > > > reference
> > > > > > > > > > > > to
> > > > > > > > > > > > > file segments around, and reuse them as needed or
> > > > > something?
> > > > > > > And
> > > > > > > > > > then
> > > > > > > > > > > or
> > > > > > > > > > > > > restart, the references to those free segment files
> > are
> > > > > > > dropped?
> > > > > > > > > > > > >
> > > > > > > > > > > > > Thoughts?
> > > > > > > > > > > > >
> > > > > > > > > > > > > This is with 0.7.2.
> > > > > > > > > > > > >
> > > > > > > > > > > > > Jason
> > > > > > > > > > > > >
> > > > > > > > > > > >
> > > > > > > > > > >
> > > > > > > > > >
> > > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
--
Mike Heffner <mi...@librato.com>
Librato, Inc.
Re: large amount of disk space freed on restart
Posted by Jay Kreps <ja...@gmail.com>.
Cool, good to know.
On Fri, Jul 26, 2013 at 2:00 PM, Jason Rosenberg <jb...@squareup.com> wrote:
> Jay,
>
> My only experience so far with this is using XFS. It appears the XFS
> behavior is evolving, and in fact, we see somewhat different behavior from
> 2 of our CentOS kernel versions in use. I've been trying to ask questions
> about all this on the XFS.org mailing list, but so far, having not much
> luck understanding the xfs versioning correlated to CentOS versions.
>
> Anyway, yes, I think it would definitely be worth trying the solution you
> suggest, which would be to close the file on rotation, and re-open
> read-only. Or to close files after a few hours of not being accessed. If
> a patch for one of these approaches can be cobbled together, I'd love to
> test it out on our staging environment. I'd be willing to experiment with
> such a patch myself, although I'm not 100% of all the places to look (but
> might dive in).
>
> Xfs appears to the option of using dynamic, speculative preallocation, in
> which case it progressively doubles the amount of space reserved for a
> file, as the file grows. It does do this for all open files. If the file
> is closed, it will then release the preallocated space not in use. It's
> not clear whether this releasing of space happens immediately on close, and
> whether re-opening the file read-only immediately, will keep it from
> releasing space (still trying to gather more info on that).
>
> I haven't looked too much at the index files, but those too appear to have
> this behavior (e.g. preallocated size is always on the order of double the
> actual size, until the app is restarted).
>
> Jason
>
>
> On Fri, Jul 26, 2013 at 12:46 PM, Jay Kreps <ja...@gmail.com> wrote:
>
> > Interesting.
> >
> > Yes, Kafka keeps all log files open indefinitely. There is no inherent
> > reason this needs to be the case, though, it would be possible to LRU out
> > old file descriptors and close them if they are not accessed for a few
> > hours and then reopen on the first access. We just haven't implemented
> > anything like that.
> >
> > It would be good to understand this a little better. Does xfs
> pre-allocate
> > space for all open files? Perhaps just closing the file on log role and
> > opening it read-only would solve the issue? Is this at all related to the
> > use of sparse files for the indexes (i.e.
> RandomAccessFile.setLength(10MB)
> > when we create the index)? Does this effect other filesystems or just
> xfs?
> >
> > -Jay
> >
> >
> > On Fri, Jul 26, 2013 at 12:42 AM, Jason Rosenberg <jb...@squareup.com>
> > wrote:
> >
> > > It looks like xfs will reclaim the preallocated space for a file, after
> > it
> > > is closed.
> > >
> > > Does kafka close a file after it has reached it's max size and started
> > > writing to the next log file in sequence? Or does it keep all open
> until
> > > they are deleted, or the server quits (that's what it seems like).
> > >
> > > I could imagine that it might need to keep log files open, in order to
> > > allow consumers access to them. But does it keep them open
> indefinitely,
> > > after there is no longer any data to be written to them, and no
> consumers
> > > are currently attempting to read from them?
> > >
> > > Jason
> > >
> > >
> > > On Tue, Jul 16, 2013 at 4:32 PM, Jay Kreps <ja...@gmail.com>
> wrote:
> > >
> > > > Interesting. Yes it will respect whatever setting it is given for new
> > > > segments created from that point on.
> > > >
> > > > -Jay
> > > >
> > > >
> > > > On Tue, Jul 16, 2013 at 11:23 AM, Jason Rosenberg <jb...@squareup.com>
> > > > wrote:
> > > >
> > > > > Ok,
> > > > >
> > > > > An update on this. It seems we are using XFS, which is available
> in
> > > > newer
> > > > > versions of Centos. It definitely does pre-allocate space as a
> file
> > > > grows,
> > > > > see:
> > > > >
> > > > >
> > > >
> > >
> >
> http://serverfault.com/questions/406069/why-are-my-xfs-filesystems-suddenly-consuming-more-space-and-full-of-sparse-file
> > > > >
> > > > > Apparently it's not hard-allocated space, and would be released
> under
> > > > > resource pressure....seems we may need to update how we monitor
> disk
> > > > space
> > > > > usage, etc....
> > > > >
> > > > > But, it seems that the default log file size of 1.1Gb, causes it to
> > > jump
> > > > to
> > > > > preallocate an extra Gb. So, in theory, if I set a strategic log
> > file
> > > > > size to be just under the threshold that forces it to exponentially
> > > > double
> > > > > the size from 1Gb to 2Gb, I should be able to mostly solve this
> > issue.
> > > > > E.g. use 950Mb instead of 1.1Gb max log file size.
> > > > >
> > > > > If I change the max log file size for a broker, and restart it,
> will
> > it
> > > > > respect the new size going forward?
> > > > >
> > > > > Jason
> > > > >
> > > > >
> > > > > On Sun, Jul 14, 2013 at 9:44 AM, Jay Kreps <ja...@gmail.com>
> > > wrote:
> > > > >
> > > > > > Hey Jason,
> > > > > >
> > > > > > As Jun says, we haven't seen that issue and no one else has
> > reported
> > > > that
> > > > > > but it sounds like a bug of some kind.
> > > > > >
> > > > > > In 0.7 we don't do any preallocation of anything. The only time
> > files
> > > > > > shrink is during recovery--we re-checksum all messages that may
> not
> > > > have
> > > > > > been flushed and if any invalid messages are found we truncate
> them
> > > > off.
> > > > > > This would only occur after an unclean shutdown (kill -9) and you
> > > would
> > > > > get
> > > > > > a bunch of errors in log warning you this was happening.
> > > > > >
> > > > > > -Jay
> > > > > >
> > > > > >
> > > > > >
> > > > > > On Sun, Jul 14, 2013 at 1:36 AM, Jason Rosenberg <
> jbr@squareup.com
> > >
> > > > > wrote:
> > > > > >
> > > > > > > An update on this. It appears that the phenomenon I'm seeing
> is
> > > that
> > > > > > disk
> > > > > > > space is freed on restart, but it's not due files getting
> deleted
> > > on
> > > > > > > restart, but instead files are getting truncated on restart.
> It
> > > > > appears
> > > > > > > that log files get pre-allocated to a larger size than is used
> > > right
> > > > > > away.
> > > > > > > Upon restart, they get truncated to the size of the file that
> > > > actually
> > > > > > > contains data. Does this make sense?
> > > > > > >
> > > > > > > Before restart, I see a large number of log files size 2.1Gb.
> > Upon
> > > > > > > restart, the disk space reclaimed drops to almost half that, on
> > > > > average.
> > > > > > >
> > > > > > > Thoughts?
> > > > > > >
> > > > > > > Jason
> > > > > > >
> > > > > > >
> > > > > > > On Thu, May 23, 2013 at 8:55 PM, Jun Rao <ju...@gmail.com>
> > wrote:
> > > > > > >
> > > > > > > > I haven't seen this issue before. We do have ~1K topics in
> one
> > of
> > > > the
> > > > > > > Kafka
> > > > > > > > clusters at LinkedIn.
> > > > > > > >
> > > > > > > > Thanks,
> > > > > > > >
> > > > > > > > Jun
> > > > > > > >
> > > > > > > >
> > > > > > > > On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <
> > > > jbr@squareup.com>
> > > > > > > > wrote:
> > > > > > > >
> > > > > > > > > Yeah, that's what it looks like to me (looking at the
> code).
> > > So,
> > > > > I'm
> > > > > > > > > guessing it's some os level caching, resource recycling.
> > Have
> > > > you
> > > > > > ever
> > > > > > > > > heard of this happening? One thing that might be different
> > in
> > > my
> > > > > > usage
> > > > > > > > > from the norm is a relatively large number of topics (e.g.
> > ~2K
> > > > > > topics).
> > > > > > > > >
> > > > > > > > > Jason
> > > > > > > > >
> > > > > > > > >
> > > > > > > > > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <junrao@gmail.com
> >
> > > > wrote:
> > > > > > > > >
> > > > > > > > > > Jason,
> > > > > > > > > >
> > > > > > > > > > Kafka closes the handler of all delete files. Otherwise,
> > the
> > > > > broker
> > > > > > > > will
> > > > > > > > > > run out of file handler quickly.
> > > > > > > > > >
> > > > > > > > > > Thanks,
> > > > > > > > > >
> > > > > > > > > > Jun
> > > > > > > > > >
> > > > > > > > > >
> > > > > > > > > > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <
> > > > > > jbr@squareup.com>
> > > > > > > > > > wrote:
> > > > > > > > > >
> > > > > > > > > > > So, does this indicate kafka (or the jvm itself) is not
> > > > > > > aggressively
> > > > > > > > > > > closing file handles of deleted files? Is there a fix
> > for
> > > > > this?
> > > > > > > Or
> > > > > > > > is
> > > > > > > > > > > there not likely anything to be done? What happens if
> > the
> > > > disk
> > > > > > > fills
> > > > > > > > > up
> > > > > > > > > > > with file handles for phantom deleted files?
> > > > > > > > > > >
> > > > > > > > > > > Jason
> > > > > > > > > > >
> > > > > > > > > > >
> > > > > > > > > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <
> > > jc@box.com
> > > > >
> > > > > > > wrote:
> > > > > > > > > > >
> > > > > > > > > > > > It isn't uncommon if a process has an open file
> handle
> > > on a
> > > > > > file
> > > > > > > > that
> > > > > > > > > > is
> > > > > > > > > > > > deleted, the space is not freed until the handle is
> > > closed.
> > > > > So
> > > > > > > > > > restarting
> > > > > > > > > > > > the process that has a handle on the file would cause
> > the
> > > > > space
> > > > > > > to
> > > > > > > > be
> > > > > > > > > > > freed
> > > > > > > > > > > > also.
> > > > > > > > > > > >
> > > > > > > > > > > > You can troubleshoot that with lsof.
> > > > > > > > > > > > Normally, I see 2-4 log segments deleted every hour
> in
> > my
> > > > > > > brokers.
> > > > > > > > I
> > > > > > > > > > see
> > > > > > > > > > > > log lines like this:
> > > > > > > > > > > >
> > > > > > > > > > > > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0]
> > > > > > > log.LogManager -
> > > > > > > > > > > > Deleting log segment 00000000035434043157.kafka from
> > > > > <redacted
> > > > > > > > topic>
> > > > > > > > > > > >
> > > > > > > > > > > > However, it seems like if I restart the broker, a
> > massive
> > > > > > amount
> > > > > > > of
> > > > > > > > > > disk
> > > > > > > > > > > > space is freed (without a corresponding flood of
> these
> > > log
> > > > > > > segment
> > > > > > > > > > > deleted
> > > > > > > > > > > > messages). Is there an explanation for this? Does
> > kafka
> > > > > keep
> > > > > > > > > > reference
> > > > > > > > > > > to
> > > > > > > > > > > > file segments around, and reuse them as needed or
> > > > something?
> > > > > > And
> > > > > > > > > then
> > > > > > > > > > or
> > > > > > > > > > > > restart, the references to those free segment files
> are
> > > > > > dropped?
> > > > > > > > > > > >
> > > > > > > > > > > > Thoughts?
> > > > > > > > > > > >
> > > > > > > > > > > > This is with 0.7.2.
> > > > > > > > > > > >
> > > > > > > > > > > > Jason
> > > > > > > > > > > >
> > > > > > > > > > >
> > > > > > > > > >
> > > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
Re: large amount of disk space freed on restart
Posted by Jason Rosenberg <jb...@squareup.com>.
Jay,
My only experience so far with this is using XFS. It appears the XFS
behavior is evolving, and in fact, we see somewhat different behavior from
2 of our CentOS kernel versions in use. I've been trying to ask questions
about all this on the XFS.org mailing list, but so far, having not much
luck understanding the xfs versioning correlated to CentOS versions.
Anyway, yes, I think it would definitely be worth trying the solution you
suggest, which would be to close the file on rotation, and re-open
read-only. Or to close files after a few hours of not being accessed. If
a patch for one of these approaches can be cobbled together, I'd love to
test it out on our staging environment. I'd be willing to experiment with
such a patch myself, although I'm not 100% of all the places to look (but
might dive in).
Xfs appears to the option of using dynamic, speculative preallocation, in
which case it progressively doubles the amount of space reserved for a
file, as the file grows. It does do this for all open files. If the file
is closed, it will then release the preallocated space not in use. It's
not clear whether this releasing of space happens immediately on close, and
whether re-opening the file read-only immediately, will keep it from
releasing space (still trying to gather more info on that).
I haven't looked too much at the index files, but those too appear to have
this behavior (e.g. preallocated size is always on the order of double the
actual size, until the app is restarted).
Jason
On Fri, Jul 26, 2013 at 12:46 PM, Jay Kreps <ja...@gmail.com> wrote:
> Interesting.
>
> Yes, Kafka keeps all log files open indefinitely. There is no inherent
> reason this needs to be the case, though, it would be possible to LRU out
> old file descriptors and close them if they are not accessed for a few
> hours and then reopen on the first access. We just haven't implemented
> anything like that.
>
> It would be good to understand this a little better. Does xfs pre-allocate
> space for all open files? Perhaps just closing the file on log role and
> opening it read-only would solve the issue? Is this at all related to the
> use of sparse files for the indexes (i.e. RandomAccessFile.setLength(10MB)
> when we create the index)? Does this effect other filesystems or just xfs?
>
> -Jay
>
>
> On Fri, Jul 26, 2013 at 12:42 AM, Jason Rosenberg <jb...@squareup.com>
> wrote:
>
> > It looks like xfs will reclaim the preallocated space for a file, after
> it
> > is closed.
> >
> > Does kafka close a file after it has reached it's max size and started
> > writing to the next log file in sequence? Or does it keep all open until
> > they are deleted, or the server quits (that's what it seems like).
> >
> > I could imagine that it might need to keep log files open, in order to
> > allow consumers access to them. But does it keep them open indefinitely,
> > after there is no longer any data to be written to them, and no consumers
> > are currently attempting to read from them?
> >
> > Jason
> >
> >
> > On Tue, Jul 16, 2013 at 4:32 PM, Jay Kreps <ja...@gmail.com> wrote:
> >
> > > Interesting. Yes it will respect whatever setting it is given for new
> > > segments created from that point on.
> > >
> > > -Jay
> > >
> > >
> > > On Tue, Jul 16, 2013 at 11:23 AM, Jason Rosenberg <jb...@squareup.com>
> > > wrote:
> > >
> > > > Ok,
> > > >
> > > > An update on this. It seems we are using XFS, which is available in
> > > newer
> > > > versions of Centos. It definitely does pre-allocate space as a file
> > > grows,
> > > > see:
> > > >
> > > >
> > >
> >
> http://serverfault.com/questions/406069/why-are-my-xfs-filesystems-suddenly-consuming-more-space-and-full-of-sparse-file
> > > >
> > > > Apparently it's not hard-allocated space, and would be released under
> > > > resource pressure....seems we may need to update how we monitor disk
> > > space
> > > > usage, etc....
> > > >
> > > > But, it seems that the default log file size of 1.1Gb, causes it to
> > jump
> > > to
> > > > preallocate an extra Gb. So, in theory, if I set a strategic log
> file
> > > > size to be just under the threshold that forces it to exponentially
> > > double
> > > > the size from 1Gb to 2Gb, I should be able to mostly solve this
> issue.
> > > > E.g. use 950Mb instead of 1.1Gb max log file size.
> > > >
> > > > If I change the max log file size for a broker, and restart it, will
> it
> > > > respect the new size going forward?
> > > >
> > > > Jason
> > > >
> > > >
> > > > On Sun, Jul 14, 2013 at 9:44 AM, Jay Kreps <ja...@gmail.com>
> > wrote:
> > > >
> > > > > Hey Jason,
> > > > >
> > > > > As Jun says, we haven't seen that issue and no one else has
> reported
> > > that
> > > > > but it sounds like a bug of some kind.
> > > > >
> > > > > In 0.7 we don't do any preallocation of anything. The only time
> files
> > > > > shrink is during recovery--we re-checksum all messages that may not
> > > have
> > > > > been flushed and if any invalid messages are found we truncate them
> > > off.
> > > > > This would only occur after an unclean shutdown (kill -9) and you
> > would
> > > > get
> > > > > a bunch of errors in log warning you this was happening.
> > > > >
> > > > > -Jay
> > > > >
> > > > >
> > > > >
> > > > > On Sun, Jul 14, 2013 at 1:36 AM, Jason Rosenberg <jbr@squareup.com
> >
> > > > wrote:
> > > > >
> > > > > > An update on this. It appears that the phenomenon I'm seeing is
> > that
> > > > > disk
> > > > > > space is freed on restart, but it's not due files getting deleted
> > on
> > > > > > restart, but instead files are getting truncated on restart. It
> > > > appears
> > > > > > that log files get pre-allocated to a larger size than is used
> > right
> > > > > away.
> > > > > > Upon restart, they get truncated to the size of the file that
> > > actually
> > > > > > contains data. Does this make sense?
> > > > > >
> > > > > > Before restart, I see a large number of log files size 2.1Gb.
> Upon
> > > > > > restart, the disk space reclaimed drops to almost half that, on
> > > > average.
> > > > > >
> > > > > > Thoughts?
> > > > > >
> > > > > > Jason
> > > > > >
> > > > > >
> > > > > > On Thu, May 23, 2013 at 8:55 PM, Jun Rao <ju...@gmail.com>
> wrote:
> > > > > >
> > > > > > > I haven't seen this issue before. We do have ~1K topics in one
> of
> > > the
> > > > > > Kafka
> > > > > > > clusters at LinkedIn.
> > > > > > >
> > > > > > > Thanks,
> > > > > > >
> > > > > > > Jun
> > > > > > >
> > > > > > >
> > > > > > > On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <
> > > jbr@squareup.com>
> > > > > > > wrote:
> > > > > > >
> > > > > > > > Yeah, that's what it looks like to me (looking at the code).
> > So,
> > > > I'm
> > > > > > > > guessing it's some os level caching, resource recycling.
> Have
> > > you
> > > > > ever
> > > > > > > > heard of this happening? One thing that might be different
> in
> > my
> > > > > usage
> > > > > > > > from the norm is a relatively large number of topics (e.g.
> ~2K
> > > > > topics).
> > > > > > > >
> > > > > > > > Jason
> > > > > > > >
> > > > > > > >
> > > > > > > > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <ju...@gmail.com>
> > > wrote:
> > > > > > > >
> > > > > > > > > Jason,
> > > > > > > > >
> > > > > > > > > Kafka closes the handler of all delete files. Otherwise,
> the
> > > > broker
> > > > > > > will
> > > > > > > > > run out of file handler quickly.
> > > > > > > > >
> > > > > > > > > Thanks,
> > > > > > > > >
> > > > > > > > > Jun
> > > > > > > > >
> > > > > > > > >
> > > > > > > > > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <
> > > > > jbr@squareup.com>
> > > > > > > > > wrote:
> > > > > > > > >
> > > > > > > > > > So, does this indicate kafka (or the jvm itself) is not
> > > > > > aggressively
> > > > > > > > > > closing file handles of deleted files? Is there a fix
> for
> > > > this?
> > > > > > Or
> > > > > > > is
> > > > > > > > > > there not likely anything to be done? What happens if
> the
> > > disk
> > > > > > fills
> > > > > > > > up
> > > > > > > > > > with file handles for phantom deleted files?
> > > > > > > > > >
> > > > > > > > > > Jason
> > > > > > > > > >
> > > > > > > > > >
> > > > > > > > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <
> > jc@box.com
> > > >
> > > > > > wrote:
> > > > > > > > > >
> > > > > > > > > > > It isn't uncommon if a process has an open file handle
> > on a
> > > > > file
> > > > > > > that
> > > > > > > > > is
> > > > > > > > > > > deleted, the space is not freed until the handle is
> > closed.
> > > > So
> > > > > > > > > restarting
> > > > > > > > > > > the process that has a handle on the file would cause
> the
> > > > space
> > > > > > to
> > > > > > > be
> > > > > > > > > > freed
> > > > > > > > > > > also.
> > > > > > > > > > >
> > > > > > > > > > > You can troubleshoot that with lsof.
> > > > > > > > > > > Normally, I see 2-4 log segments deleted every hour in
> my
> > > > > > brokers.
> > > > > > > I
> > > > > > > > > see
> > > > > > > > > > > log lines like this:
> > > > > > > > > > >
> > > > > > > > > > > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0]
> > > > > > log.LogManager -
> > > > > > > > > > > Deleting log segment 00000000035434043157.kafka from
> > > > <redacted
> > > > > > > topic>
> > > > > > > > > > >
> > > > > > > > > > > However, it seems like if I restart the broker, a
> massive
> > > > > amount
> > > > > > of
> > > > > > > > > disk
> > > > > > > > > > > space is freed (without a corresponding flood of these
> > log
> > > > > > segment
> > > > > > > > > > deleted
> > > > > > > > > > > messages). Is there an explanation for this? Does
> kafka
> > > > keep
> > > > > > > > > reference
> > > > > > > > > > to
> > > > > > > > > > > file segments around, and reuse them as needed or
> > > something?
> > > > > And
> > > > > > > > then
> > > > > > > > > or
> > > > > > > > > > > restart, the references to those free segment files are
> > > > > dropped?
> > > > > > > > > > >
> > > > > > > > > > > Thoughts?
> > > > > > > > > > >
> > > > > > > > > > > This is with 0.7.2.
> > > > > > > > > > >
> > > > > > > > > > > Jason
> > > > > > > > > > >
> > > > > > > > > >
> > > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
Re: large amount of disk space freed on restart
Posted by Jay Kreps <ja...@gmail.com>.
Interesting.
Yes, Kafka keeps all log files open indefinitely. There is no inherent
reason this needs to be the case, though, it would be possible to LRU out
old file descriptors and close them if they are not accessed for a few
hours and then reopen on the first access. We just haven't implemented
anything like that.
It would be good to understand this a little better. Does xfs pre-allocate
space for all open files? Perhaps just closing the file on log role and
opening it read-only would solve the issue? Is this at all related to the
use of sparse files for the indexes (i.e. RandomAccessFile.setLength(10MB)
when we create the index)? Does this effect other filesystems or just xfs?
-Jay
On Fri, Jul 26, 2013 at 12:42 AM, Jason Rosenberg <jb...@squareup.com> wrote:
> It looks like xfs will reclaim the preallocated space for a file, after it
> is closed.
>
> Does kafka close a file after it has reached it's max size and started
> writing to the next log file in sequence? Or does it keep all open until
> they are deleted, or the server quits (that's what it seems like).
>
> I could imagine that it might need to keep log files open, in order to
> allow consumers access to them. But does it keep them open indefinitely,
> after there is no longer any data to be written to them, and no consumers
> are currently attempting to read from them?
>
> Jason
>
>
> On Tue, Jul 16, 2013 at 4:32 PM, Jay Kreps <ja...@gmail.com> wrote:
>
> > Interesting. Yes it will respect whatever setting it is given for new
> > segments created from that point on.
> >
> > -Jay
> >
> >
> > On Tue, Jul 16, 2013 at 11:23 AM, Jason Rosenberg <jb...@squareup.com>
> > wrote:
> >
> > > Ok,
> > >
> > > An update on this. It seems we are using XFS, which is available in
> > newer
> > > versions of Centos. It definitely does pre-allocate space as a file
> > grows,
> > > see:
> > >
> > >
> >
> http://serverfault.com/questions/406069/why-are-my-xfs-filesystems-suddenly-consuming-more-space-and-full-of-sparse-file
> > >
> > > Apparently it's not hard-allocated space, and would be released under
> > > resource pressure....seems we may need to update how we monitor disk
> > space
> > > usage, etc....
> > >
> > > But, it seems that the default log file size of 1.1Gb, causes it to
> jump
> > to
> > > preallocate an extra Gb. So, in theory, if I set a strategic log file
> > > size to be just under the threshold that forces it to exponentially
> > double
> > > the size from 1Gb to 2Gb, I should be able to mostly solve this issue.
> > > E.g. use 950Mb instead of 1.1Gb max log file size.
> > >
> > > If I change the max log file size for a broker, and restart it, will it
> > > respect the new size going forward?
> > >
> > > Jason
> > >
> > >
> > > On Sun, Jul 14, 2013 at 9:44 AM, Jay Kreps <ja...@gmail.com>
> wrote:
> > >
> > > > Hey Jason,
> > > >
> > > > As Jun says, we haven't seen that issue and no one else has reported
> > that
> > > > but it sounds like a bug of some kind.
> > > >
> > > > In 0.7 we don't do any preallocation of anything. The only time files
> > > > shrink is during recovery--we re-checksum all messages that may not
> > have
> > > > been flushed and if any invalid messages are found we truncate them
> > off.
> > > > This would only occur after an unclean shutdown (kill -9) and you
> would
> > > get
> > > > a bunch of errors in log warning you this was happening.
> > > >
> > > > -Jay
> > > >
> > > >
> > > >
> > > > On Sun, Jul 14, 2013 at 1:36 AM, Jason Rosenberg <jb...@squareup.com>
> > > wrote:
> > > >
> > > > > An update on this. It appears that the phenomenon I'm seeing is
> that
> > > > disk
> > > > > space is freed on restart, but it's not due files getting deleted
> on
> > > > > restart, but instead files are getting truncated on restart. It
> > > appears
> > > > > that log files get pre-allocated to a larger size than is used
> right
> > > > away.
> > > > > Upon restart, they get truncated to the size of the file that
> > actually
> > > > > contains data. Does this make sense?
> > > > >
> > > > > Before restart, I see a large number of log files size 2.1Gb. Upon
> > > > > restart, the disk space reclaimed drops to almost half that, on
> > > average.
> > > > >
> > > > > Thoughts?
> > > > >
> > > > > Jason
> > > > >
> > > > >
> > > > > On Thu, May 23, 2013 at 8:55 PM, Jun Rao <ju...@gmail.com> wrote:
> > > > >
> > > > > > I haven't seen this issue before. We do have ~1K topics in one of
> > the
> > > > > Kafka
> > > > > > clusters at LinkedIn.
> > > > > >
> > > > > > Thanks,
> > > > > >
> > > > > > Jun
> > > > > >
> > > > > >
> > > > > > On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <
> > jbr@squareup.com>
> > > > > > wrote:
> > > > > >
> > > > > > > Yeah, that's what it looks like to me (looking at the code).
> So,
> > > I'm
> > > > > > > guessing it's some os level caching, resource recycling. Have
> > you
> > > > ever
> > > > > > > heard of this happening? One thing that might be different in
> my
> > > > usage
> > > > > > > from the norm is a relatively large number of topics (e.g. ~2K
> > > > topics).
> > > > > > >
> > > > > > > Jason
> > > > > > >
> > > > > > >
> > > > > > > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <ju...@gmail.com>
> > wrote:
> > > > > > >
> > > > > > > > Jason,
> > > > > > > >
> > > > > > > > Kafka closes the handler of all delete files. Otherwise, the
> > > broker
> > > > > > will
> > > > > > > > run out of file handler quickly.
> > > > > > > >
> > > > > > > > Thanks,
> > > > > > > >
> > > > > > > > Jun
> > > > > > > >
> > > > > > > >
> > > > > > > > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <
> > > > jbr@squareup.com>
> > > > > > > > wrote:
> > > > > > > >
> > > > > > > > > So, does this indicate kafka (or the jvm itself) is not
> > > > > aggressively
> > > > > > > > > closing file handles of deleted files? Is there a fix for
> > > this?
> > > > > Or
> > > > > > is
> > > > > > > > > there not likely anything to be done? What happens if the
> > disk
> > > > > fills
> > > > > > > up
> > > > > > > > > with file handles for phantom deleted files?
> > > > > > > > >
> > > > > > > > > Jason
> > > > > > > > >
> > > > > > > > >
> > > > > > > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <
> jc@box.com
> > >
> > > > > wrote:
> > > > > > > > >
> > > > > > > > > > It isn't uncommon if a process has an open file handle
> on a
> > > > file
> > > > > > that
> > > > > > > > is
> > > > > > > > > > deleted, the space is not freed until the handle is
> closed.
> > > So
> > > > > > > > restarting
> > > > > > > > > > the process that has a handle on the file would cause the
> > > space
> > > > > to
> > > > > > be
> > > > > > > > > freed
> > > > > > > > > > also.
> > > > > > > > > >
> > > > > > > > > > You can troubleshoot that with lsof.
> > > > > > > > > > Normally, I see 2-4 log segments deleted every hour in my
> > > > > brokers.
> > > > > > I
> > > > > > > > see
> > > > > > > > > > log lines like this:
> > > > > > > > > >
> > > > > > > > > > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0]
> > > > > log.LogManager -
> > > > > > > > > > Deleting log segment 00000000035434043157.kafka from
> > > <redacted
> > > > > > topic>
> > > > > > > > > >
> > > > > > > > > > However, it seems like if I restart the broker, a massive
> > > > amount
> > > > > of
> > > > > > > > disk
> > > > > > > > > > space is freed (without a corresponding flood of these
> log
> > > > > segment
> > > > > > > > > deleted
> > > > > > > > > > messages). Is there an explanation for this? Does kafka
> > > keep
> > > > > > > > reference
> > > > > > > > > to
> > > > > > > > > > file segments around, and reuse them as needed or
> > something?
> > > > And
> > > > > > > then
> > > > > > > > or
> > > > > > > > > > restart, the references to those free segment files are
> > > > dropped?
> > > > > > > > > >
> > > > > > > > > > Thoughts?
> > > > > > > > > >
> > > > > > > > > > This is with 0.7.2.
> > > > > > > > > >
> > > > > > > > > > Jason
> > > > > > > > > >
> > > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
Re: large amount of disk space freed on restart
Posted by Jason Rosenberg <jb...@squareup.com>.
It looks like xfs will reclaim the preallocated space for a file, after it
is closed.
Does kafka close a file after it has reached it's max size and started
writing to the next log file in sequence? Or does it keep all open until
they are deleted, or the server quits (that's what it seems like).
I could imagine that it might need to keep log files open, in order to
allow consumers access to them. But does it keep them open indefinitely,
after there is no longer any data to be written to them, and no consumers
are currently attempting to read from them?
Jason
On Tue, Jul 16, 2013 at 4:32 PM, Jay Kreps <ja...@gmail.com> wrote:
> Interesting. Yes it will respect whatever setting it is given for new
> segments created from that point on.
>
> -Jay
>
>
> On Tue, Jul 16, 2013 at 11:23 AM, Jason Rosenberg <jb...@squareup.com>
> wrote:
>
> > Ok,
> >
> > An update on this. It seems we are using XFS, which is available in
> newer
> > versions of Centos. It definitely does pre-allocate space as a file
> grows,
> > see:
> >
> >
> http://serverfault.com/questions/406069/why-are-my-xfs-filesystems-suddenly-consuming-more-space-and-full-of-sparse-file
> >
> > Apparently it's not hard-allocated space, and would be released under
> > resource pressure....seems we may need to update how we monitor disk
> space
> > usage, etc....
> >
> > But, it seems that the default log file size of 1.1Gb, causes it to jump
> to
> > preallocate an extra Gb. So, in theory, if I set a strategic log file
> > size to be just under the threshold that forces it to exponentially
> double
> > the size from 1Gb to 2Gb, I should be able to mostly solve this issue.
> > E.g. use 950Mb instead of 1.1Gb max log file size.
> >
> > If I change the max log file size for a broker, and restart it, will it
> > respect the new size going forward?
> >
> > Jason
> >
> >
> > On Sun, Jul 14, 2013 at 9:44 AM, Jay Kreps <ja...@gmail.com> wrote:
> >
> > > Hey Jason,
> > >
> > > As Jun says, we haven't seen that issue and no one else has reported
> that
> > > but it sounds like a bug of some kind.
> > >
> > > In 0.7 we don't do any preallocation of anything. The only time files
> > > shrink is during recovery--we re-checksum all messages that may not
> have
> > > been flushed and if any invalid messages are found we truncate them
> off.
> > > This would only occur after an unclean shutdown (kill -9) and you would
> > get
> > > a bunch of errors in log warning you this was happening.
> > >
> > > -Jay
> > >
> > >
> > >
> > > On Sun, Jul 14, 2013 at 1:36 AM, Jason Rosenberg <jb...@squareup.com>
> > wrote:
> > >
> > > > An update on this. It appears that the phenomenon I'm seeing is that
> > > disk
> > > > space is freed on restart, but it's not due files getting deleted on
> > > > restart, but instead files are getting truncated on restart. It
> > appears
> > > > that log files get pre-allocated to a larger size than is used right
> > > away.
> > > > Upon restart, they get truncated to the size of the file that
> actually
> > > > contains data. Does this make sense?
> > > >
> > > > Before restart, I see a large number of log files size 2.1Gb. Upon
> > > > restart, the disk space reclaimed drops to almost half that, on
> > average.
> > > >
> > > > Thoughts?
> > > >
> > > > Jason
> > > >
> > > >
> > > > On Thu, May 23, 2013 at 8:55 PM, Jun Rao <ju...@gmail.com> wrote:
> > > >
> > > > > I haven't seen this issue before. We do have ~1K topics in one of
> the
> > > > Kafka
> > > > > clusters at LinkedIn.
> > > > >
> > > > > Thanks,
> > > > >
> > > > > Jun
> > > > >
> > > > >
> > > > > On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <
> jbr@squareup.com>
> > > > > wrote:
> > > > >
> > > > > > Yeah, that's what it looks like to me (looking at the code). So,
> > I'm
> > > > > > guessing it's some os level caching, resource recycling. Have
> you
> > > ever
> > > > > > heard of this happening? One thing that might be different in my
> > > usage
> > > > > > from the norm is a relatively large number of topics (e.g. ~2K
> > > topics).
> > > > > >
> > > > > > Jason
> > > > > >
> > > > > >
> > > > > > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <ju...@gmail.com>
> wrote:
> > > > > >
> > > > > > > Jason,
> > > > > > >
> > > > > > > Kafka closes the handler of all delete files. Otherwise, the
> > broker
> > > > > will
> > > > > > > run out of file handler quickly.
> > > > > > >
> > > > > > > Thanks,
> > > > > > >
> > > > > > > Jun
> > > > > > >
> > > > > > >
> > > > > > > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <
> > > jbr@squareup.com>
> > > > > > > wrote:
> > > > > > >
> > > > > > > > So, does this indicate kafka (or the jvm itself) is not
> > > > aggressively
> > > > > > > > closing file handles of deleted files? Is there a fix for
> > this?
> > > > Or
> > > > > is
> > > > > > > > there not likely anything to be done? What happens if the
> disk
> > > > fills
> > > > > > up
> > > > > > > > with file handles for phantom deleted files?
> > > > > > > >
> > > > > > > > Jason
> > > > > > > >
> > > > > > > >
> > > > > > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <jc@box.com
> >
> > > > wrote:
> > > > > > > >
> > > > > > > > > It isn't uncommon if a process has an open file handle on a
> > > file
> > > > > that
> > > > > > > is
> > > > > > > > > deleted, the space is not freed until the handle is closed.
> > So
> > > > > > > restarting
> > > > > > > > > the process that has a handle on the file would cause the
> > space
> > > > to
> > > > > be
> > > > > > > > freed
> > > > > > > > > also.
> > > > > > > > >
> > > > > > > > > You can troubleshoot that with lsof.
> > > > > > > > > Normally, I see 2-4 log segments deleted every hour in my
> > > > brokers.
> > > > > I
> > > > > > > see
> > > > > > > > > log lines like this:
> > > > > > > > >
> > > > > > > > > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0]
> > > > log.LogManager -
> > > > > > > > > Deleting log segment 00000000035434043157.kafka from
> > <redacted
> > > > > topic>
> > > > > > > > >
> > > > > > > > > However, it seems like if I restart the broker, a massive
> > > amount
> > > > of
> > > > > > > disk
> > > > > > > > > space is freed (without a corresponding flood of these log
> > > > segment
> > > > > > > > deleted
> > > > > > > > > messages). Is there an explanation for this? Does kafka
> > keep
> > > > > > > reference
> > > > > > > > to
> > > > > > > > > file segments around, and reuse them as needed or
> something?
> > > And
> > > > > > then
> > > > > > > or
> > > > > > > > > restart, the references to those free segment files are
> > > dropped?
> > > > > > > > >
> > > > > > > > > Thoughts?
> > > > > > > > >
> > > > > > > > > This is with 0.7.2.
> > > > > > > > >
> > > > > > > > > Jason
> > > > > > > > >
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
Re: large amount of disk space freed on restart
Posted by Jay Kreps <ja...@gmail.com>.
Interesting. Yes it will respect whatever setting it is given for new
segments created from that point on.
-Jay
On Tue, Jul 16, 2013 at 11:23 AM, Jason Rosenberg <jb...@squareup.com> wrote:
> Ok,
>
> An update on this. It seems we are using XFS, which is available in newer
> versions of Centos. It definitely does pre-allocate space as a file grows,
> see:
>
> http://serverfault.com/questions/406069/why-are-my-xfs-filesystems-suddenly-consuming-more-space-and-full-of-sparse-file
>
> Apparently it's not hard-allocated space, and would be released under
> resource pressure....seems we may need to update how we monitor disk space
> usage, etc....
>
> But, it seems that the default log file size of 1.1Gb, causes it to jump to
> preallocate an extra Gb. So, in theory, if I set a strategic log file
> size to be just under the threshold that forces it to exponentially double
> the size from 1Gb to 2Gb, I should be able to mostly solve this issue.
> E.g. use 950Mb instead of 1.1Gb max log file size.
>
> If I change the max log file size for a broker, and restart it, will it
> respect the new size going forward?
>
> Jason
>
>
> On Sun, Jul 14, 2013 at 9:44 AM, Jay Kreps <ja...@gmail.com> wrote:
>
> > Hey Jason,
> >
> > As Jun says, we haven't seen that issue and no one else has reported that
> > but it sounds like a bug of some kind.
> >
> > In 0.7 we don't do any preallocation of anything. The only time files
> > shrink is during recovery--we re-checksum all messages that may not have
> > been flushed and if any invalid messages are found we truncate them off.
> > This would only occur after an unclean shutdown (kill -9) and you would
> get
> > a bunch of errors in log warning you this was happening.
> >
> > -Jay
> >
> >
> >
> > On Sun, Jul 14, 2013 at 1:36 AM, Jason Rosenberg <jb...@squareup.com>
> wrote:
> >
> > > An update on this. It appears that the phenomenon I'm seeing is that
> > disk
> > > space is freed on restart, but it's not due files getting deleted on
> > > restart, but instead files are getting truncated on restart. It
> appears
> > > that log files get pre-allocated to a larger size than is used right
> > away.
> > > Upon restart, they get truncated to the size of the file that actually
> > > contains data. Does this make sense?
> > >
> > > Before restart, I see a large number of log files size 2.1Gb. Upon
> > > restart, the disk space reclaimed drops to almost half that, on
> average.
> > >
> > > Thoughts?
> > >
> > > Jason
> > >
> > >
> > > On Thu, May 23, 2013 at 8:55 PM, Jun Rao <ju...@gmail.com> wrote:
> > >
> > > > I haven't seen this issue before. We do have ~1K topics in one of the
> > > Kafka
> > > > clusters at LinkedIn.
> > > >
> > > > Thanks,
> > > >
> > > > Jun
> > > >
> > > >
> > > > On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <jb...@squareup.com>
> > > > wrote:
> > > >
> > > > > Yeah, that's what it looks like to me (looking at the code). So,
> I'm
> > > > > guessing it's some os level caching, resource recycling. Have you
> > ever
> > > > > heard of this happening? One thing that might be different in my
> > usage
> > > > > from the norm is a relatively large number of topics (e.g. ~2K
> > topics).
> > > > >
> > > > > Jason
> > > > >
> > > > >
> > > > > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <ju...@gmail.com> wrote:
> > > > >
> > > > > > Jason,
> > > > > >
> > > > > > Kafka closes the handler of all delete files. Otherwise, the
> broker
> > > > will
> > > > > > run out of file handler quickly.
> > > > > >
> > > > > > Thanks,
> > > > > >
> > > > > > Jun
> > > > > >
> > > > > >
> > > > > > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <
> > jbr@squareup.com>
> > > > > > wrote:
> > > > > >
> > > > > > > So, does this indicate kafka (or the jvm itself) is not
> > > aggressively
> > > > > > > closing file handles of deleted files? Is there a fix for
> this?
> > > Or
> > > > is
> > > > > > > there not likely anything to be done? What happens if the disk
> > > fills
> > > > > up
> > > > > > > with file handles for phantom deleted files?
> > > > > > >
> > > > > > > Jason
> > > > > > >
> > > > > > >
> > > > > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <jc...@box.com>
> > > wrote:
> > > > > > >
> > > > > > > > It isn't uncommon if a process has an open file handle on a
> > file
> > > > that
> > > > > > is
> > > > > > > > deleted, the space is not freed until the handle is closed.
> So
> > > > > > restarting
> > > > > > > > the process that has a handle on the file would cause the
> space
> > > to
> > > > be
> > > > > > > freed
> > > > > > > > also.
> > > > > > > >
> > > > > > > > You can troubleshoot that with lsof.
> > > > > > > > Normally, I see 2-4 log segments deleted every hour in my
> > > brokers.
> > > > I
> > > > > > see
> > > > > > > > log lines like this:
> > > > > > > >
> > > > > > > > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0]
> > > log.LogManager -
> > > > > > > > Deleting log segment 00000000035434043157.kafka from
> <redacted
> > > > topic>
> > > > > > > >
> > > > > > > > However, it seems like if I restart the broker, a massive
> > amount
> > > of
> > > > > > disk
> > > > > > > > space is freed (without a corresponding flood of these log
> > > segment
> > > > > > > deleted
> > > > > > > > messages). Is there an explanation for this? Does kafka
> keep
> > > > > > reference
> > > > > > > to
> > > > > > > > file segments around, and reuse them as needed or something?
> > And
> > > > > then
> > > > > > or
> > > > > > > > restart, the references to those free segment files are
> > dropped?
> > > > > > > >
> > > > > > > > Thoughts?
> > > > > > > >
> > > > > > > > This is with 0.7.2.
> > > > > > > >
> > > > > > > > Jason
> > > > > > > >
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
Re: large amount of disk space freed on restart
Posted by Jason Rosenberg <jb...@squareup.com>.
Ok,
An update on this. It seems we are using XFS, which is available in newer
versions of Centos. It definitely does pre-allocate space as a file grows,
see:
http://serverfault.com/questions/406069/why-are-my-xfs-filesystems-suddenly-consuming-more-space-and-full-of-sparse-file
Apparently it's not hard-allocated space, and would be released under
resource pressure....seems we may need to update how we monitor disk space
usage, etc....
But, it seems that the default log file size of 1.1Gb, causes it to jump to
preallocate an extra Gb. So, in theory, if I set a strategic log file
size to be just under the threshold that forces it to exponentially double
the size from 1Gb to 2Gb, I should be able to mostly solve this issue.
E.g. use 950Mb instead of 1.1Gb max log file size.
If I change the max log file size for a broker, and restart it, will it
respect the new size going forward?
Jason
On Sun, Jul 14, 2013 at 9:44 AM, Jay Kreps <ja...@gmail.com> wrote:
> Hey Jason,
>
> As Jun says, we haven't seen that issue and no one else has reported that
> but it sounds like a bug of some kind.
>
> In 0.7 we don't do any preallocation of anything. The only time files
> shrink is during recovery--we re-checksum all messages that may not have
> been flushed and if any invalid messages are found we truncate them off.
> This would only occur after an unclean shutdown (kill -9) and you would get
> a bunch of errors in log warning you this was happening.
>
> -Jay
>
>
>
> On Sun, Jul 14, 2013 at 1:36 AM, Jason Rosenberg <jb...@squareup.com> wrote:
>
> > An update on this. It appears that the phenomenon I'm seeing is that
> disk
> > space is freed on restart, but it's not due files getting deleted on
> > restart, but instead files are getting truncated on restart. It appears
> > that log files get pre-allocated to a larger size than is used right
> away.
> > Upon restart, they get truncated to the size of the file that actually
> > contains data. Does this make sense?
> >
> > Before restart, I see a large number of log files size 2.1Gb. Upon
> > restart, the disk space reclaimed drops to almost half that, on average.
> >
> > Thoughts?
> >
> > Jason
> >
> >
> > On Thu, May 23, 2013 at 8:55 PM, Jun Rao <ju...@gmail.com> wrote:
> >
> > > I haven't seen this issue before. We do have ~1K topics in one of the
> > Kafka
> > > clusters at LinkedIn.
> > >
> > > Thanks,
> > >
> > > Jun
> > >
> > >
> > > On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <jb...@squareup.com>
> > > wrote:
> > >
> > > > Yeah, that's what it looks like to me (looking at the code). So, I'm
> > > > guessing it's some os level caching, resource recycling. Have you
> ever
> > > > heard of this happening? One thing that might be different in my
> usage
> > > > from the norm is a relatively large number of topics (e.g. ~2K
> topics).
> > > >
> > > > Jason
> > > >
> > > >
> > > > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <ju...@gmail.com> wrote:
> > > >
> > > > > Jason,
> > > > >
> > > > > Kafka closes the handler of all delete files. Otherwise, the broker
> > > will
> > > > > run out of file handler quickly.
> > > > >
> > > > > Thanks,
> > > > >
> > > > > Jun
> > > > >
> > > > >
> > > > > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <
> jbr@squareup.com>
> > > > > wrote:
> > > > >
> > > > > > So, does this indicate kafka (or the jvm itself) is not
> > aggressively
> > > > > > closing file handles of deleted files? Is there a fix for this?
> > Or
> > > is
> > > > > > there not likely anything to be done? What happens if the disk
> > fills
> > > > up
> > > > > > with file handles for phantom deleted files?
> > > > > >
> > > > > > Jason
> > > > > >
> > > > > >
> > > > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <jc...@box.com>
> > wrote:
> > > > > >
> > > > > > > It isn't uncommon if a process has an open file handle on a
> file
> > > that
> > > > > is
> > > > > > > deleted, the space is not freed until the handle is closed. So
> > > > > restarting
> > > > > > > the process that has a handle on the file would cause the space
> > to
> > > be
> > > > > > freed
> > > > > > > also.
> > > > > > >
> > > > > > > You can troubleshoot that with lsof.
> > > > > > > Normally, I see 2-4 log segments deleted every hour in my
> > brokers.
> > > I
> > > > > see
> > > > > > > log lines like this:
> > > > > > >
> > > > > > > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0]
> > log.LogManager -
> > > > > > > Deleting log segment 00000000035434043157.kafka from <redacted
> > > topic>
> > > > > > >
> > > > > > > However, it seems like if I restart the broker, a massive
> amount
> > of
> > > > > disk
> > > > > > > space is freed (without a corresponding flood of these log
> > segment
> > > > > > deleted
> > > > > > > messages). Is there an explanation for this? Does kafka keep
> > > > > reference
> > > > > > to
> > > > > > > file segments around, and reuse them as needed or something?
> And
> > > > then
> > > > > or
> > > > > > > restart, the references to those free segment files are
> dropped?
> > > > > > >
> > > > > > > Thoughts?
> > > > > > >
> > > > > > > This is with 0.7.2.
> > > > > > >
> > > > > > > Jason
> > > > > > >
> > > > > >
> > > > >
> > > >
> > >
> >
>
Re: large amount of disk space freed on restart
Posted by Jay Kreps <ja...@gmail.com>.
Hey Jason,
As Jun says, we haven't seen that issue and no one else has reported that
but it sounds like a bug of some kind.
In 0.7 we don't do any preallocation of anything. The only time files
shrink is during recovery--we re-checksum all messages that may not have
been flushed and if any invalid messages are found we truncate them off.
This would only occur after an unclean shutdown (kill -9) and you would get
a bunch of errors in log warning you this was happening.
-Jay
On Sun, Jul 14, 2013 at 1:36 AM, Jason Rosenberg <jb...@squareup.com> wrote:
> An update on this. It appears that the phenomenon I'm seeing is that disk
> space is freed on restart, but it's not due files getting deleted on
> restart, but instead files are getting truncated on restart. It appears
> that log files get pre-allocated to a larger size than is used right away.
> Upon restart, they get truncated to the size of the file that actually
> contains data. Does this make sense?
>
> Before restart, I see a large number of log files size 2.1Gb. Upon
> restart, the disk space reclaimed drops to almost half that, on average.
>
> Thoughts?
>
> Jason
>
>
> On Thu, May 23, 2013 at 8:55 PM, Jun Rao <ju...@gmail.com> wrote:
>
> > I haven't seen this issue before. We do have ~1K topics in one of the
> Kafka
> > clusters at LinkedIn.
> >
> > Thanks,
> >
> > Jun
> >
> >
> > On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <jb...@squareup.com>
> > wrote:
> >
> > > Yeah, that's what it looks like to me (looking at the code). So, I'm
> > > guessing it's some os level caching, resource recycling. Have you ever
> > > heard of this happening? One thing that might be different in my usage
> > > from the norm is a relatively large number of topics (e.g. ~2K topics).
> > >
> > > Jason
> > >
> > >
> > > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <ju...@gmail.com> wrote:
> > >
> > > > Jason,
> > > >
> > > > Kafka closes the handler of all delete files. Otherwise, the broker
> > will
> > > > run out of file handler quickly.
> > > >
> > > > Thanks,
> > > >
> > > > Jun
> > > >
> > > >
> > > > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <jb...@squareup.com>
> > > > wrote:
> > > >
> > > > > So, does this indicate kafka (or the jvm itself) is not
> aggressively
> > > > > closing file handles of deleted files? Is there a fix for this?
> Or
> > is
> > > > > there not likely anything to be done? What happens if the disk
> fills
> > > up
> > > > > with file handles for phantom deleted files?
> > > > >
> > > > > Jason
> > > > >
> > > > >
> > > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <jc...@box.com>
> wrote:
> > > > >
> > > > > > It isn't uncommon if a process has an open file handle on a file
> > that
> > > > is
> > > > > > deleted, the space is not freed until the handle is closed. So
> > > > restarting
> > > > > > the process that has a handle on the file would cause the space
> to
> > be
> > > > > freed
> > > > > > also.
> > > > > >
> > > > > > You can troubleshoot that with lsof.
> > > > > > Normally, I see 2-4 log segments deleted every hour in my
> brokers.
> > I
> > > > see
> > > > > > log lines like this:
> > > > > >
> > > > > > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0]
> log.LogManager -
> > > > > > Deleting log segment 00000000035434043157.kafka from <redacted
> > topic>
> > > > > >
> > > > > > However, it seems like if I restart the broker, a massive amount
> of
> > > > disk
> > > > > > space is freed (without a corresponding flood of these log
> segment
> > > > > deleted
> > > > > > messages). Is there an explanation for this? Does kafka keep
> > > > reference
> > > > > to
> > > > > > file segments around, and reuse them as needed or something? And
> > > then
> > > > or
> > > > > > restart, the references to those free segment files are dropped?
> > > > > >
> > > > > > Thoughts?
> > > > > >
> > > > > > This is with 0.7.2.
> > > > > >
> > > > > > Jason
> > > > > >
> > > > >
> > > >
> > >
> >
>
Re: large amount of disk space freed on restart
Posted by Jason Rosenberg <jb...@squareup.com>.
An update on this. It appears that the phenomenon I'm seeing is that disk
space is freed on restart, but it's not due files getting deleted on
restart, but instead files are getting truncated on restart. It appears
that log files get pre-allocated to a larger size than is used right away.
Upon restart, they get truncated to the size of the file that actually
contains data. Does this make sense?
Before restart, I see a large number of log files size 2.1Gb. Upon
restart, the disk space reclaimed drops to almost half that, on average.
Thoughts?
Jason
On Thu, May 23, 2013 at 8:55 PM, Jun Rao <ju...@gmail.com> wrote:
> I haven't seen this issue before. We do have ~1K topics in one of the Kafka
> clusters at LinkedIn.
>
> Thanks,
>
> Jun
>
>
> On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <jb...@squareup.com>
> wrote:
>
> > Yeah, that's what it looks like to me (looking at the code). So, I'm
> > guessing it's some os level caching, resource recycling. Have you ever
> > heard of this happening? One thing that might be different in my usage
> > from the norm is a relatively large number of topics (e.g. ~2K topics).
> >
> > Jason
> >
> >
> > On Thu, May 23, 2013 at 7:14 AM, Jun Rao <ju...@gmail.com> wrote:
> >
> > > Jason,
> > >
> > > Kafka closes the handler of all delete files. Otherwise, the broker
> will
> > > run out of file handler quickly.
> > >
> > > Thanks,
> > >
> > > Jun
> > >
> > >
> > > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <jb...@squareup.com>
> > > wrote:
> > >
> > > > So, does this indicate kafka (or the jvm itself) is not aggressively
> > > > closing file handles of deleted files? Is there a fix for this? Or
> is
> > > > there not likely anything to be done? What happens if the disk fills
> > up
> > > > with file handles for phantom deleted files?
> > > >
> > > > Jason
> > > >
> > > >
> > > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <jc...@box.com> wrote:
> > > >
> > > > > It isn't uncommon if a process has an open file handle on a file
> that
> > > is
> > > > > deleted, the space is not freed until the handle is closed. So
> > > restarting
> > > > > the process that has a handle on the file would cause the space to
> be
> > > > freed
> > > > > also.
> > > > >
> > > > > You can troubleshoot that with lsof.
> > > > > Normally, I see 2-4 log segments deleted every hour in my brokers.
> I
> > > see
> > > > > log lines like this:
> > > > >
> > > > > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0] log.LogManager -
> > > > > Deleting log segment 00000000035434043157.kafka from <redacted
> topic>
> > > > >
> > > > > However, it seems like if I restart the broker, a massive amount of
> > > disk
> > > > > space is freed (without a corresponding flood of these log segment
> > > > deleted
> > > > > messages). Is there an explanation for this? Does kafka keep
> > > reference
> > > > to
> > > > > file segments around, and reuse them as needed or something? And
> > then
> > > or
> > > > > restart, the references to those free segment files are dropped?
> > > > >
> > > > > Thoughts?
> > > > >
> > > > > This is with 0.7.2.
> > > > >
> > > > > Jason
> > > > >
> > > >
> > >
> >
>
Re: large amount of disk space freed on restart
Posted by Jun Rao <ju...@gmail.com>.
I haven't seen this issue before. We do have ~1K topics in one of the Kafka
clusters at LinkedIn.
Thanks,
Jun
On Thu, May 23, 2013 at 11:05 AM, Jason Rosenberg <jb...@squareup.com> wrote:
> Yeah, that's what it looks like to me (looking at the code). So, I'm
> guessing it's some os level caching, resource recycling. Have you ever
> heard of this happening? One thing that might be different in my usage
> from the norm is a relatively large number of topics (e.g. ~2K topics).
>
> Jason
>
>
> On Thu, May 23, 2013 at 7:14 AM, Jun Rao <ju...@gmail.com> wrote:
>
> > Jason,
> >
> > Kafka closes the handler of all delete files. Otherwise, the broker will
> > run out of file handler quickly.
> >
> > Thanks,
> >
> > Jun
> >
> >
> > On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <jb...@squareup.com>
> > wrote:
> >
> > > So, does this indicate kafka (or the jvm itself) is not aggressively
> > > closing file handles of deleted files? Is there a fix for this? Or is
> > > there not likely anything to be done? What happens if the disk fills
> up
> > > with file handles for phantom deleted files?
> > >
> > > Jason
> > >
> > >
> > > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <jc...@box.com> wrote:
> > >
> > > > It isn't uncommon if a process has an open file handle on a file that
> > is
> > > > deleted, the space is not freed until the handle is closed. So
> > restarting
> > > > the process that has a handle on the file would cause the space to be
> > > freed
> > > > also.
> > > >
> > > > You can troubleshoot that with lsof.
> > > > Normally, I see 2-4 log segments deleted every hour in my brokers. I
> > see
> > > > log lines like this:
> > > >
> > > > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0] log.LogManager -
> > > > Deleting log segment 00000000035434043157.kafka from <redacted topic>
> > > >
> > > > However, it seems like if I restart the broker, a massive amount of
> > disk
> > > > space is freed (without a corresponding flood of these log segment
> > > deleted
> > > > messages). Is there an explanation for this? Does kafka keep
> > reference
> > > to
> > > > file segments around, and reuse them as needed or something? And
> then
> > or
> > > > restart, the references to those free segment files are dropped?
> > > >
> > > > Thoughts?
> > > >
> > > > This is with 0.7.2.
> > > >
> > > > Jason
> > > >
> > >
> >
>
Re: large amount of disk space freed on restart
Posted by Jason Rosenberg <jb...@squareup.com>.
Yeah, that's what it looks like to me (looking at the code). So, I'm
guessing it's some os level caching, resource recycling. Have you ever
heard of this happening? One thing that might be different in my usage
from the norm is a relatively large number of topics (e.g. ~2K topics).
Jason
On Thu, May 23, 2013 at 7:14 AM, Jun Rao <ju...@gmail.com> wrote:
> Jason,
>
> Kafka closes the handler of all delete files. Otherwise, the broker will
> run out of file handler quickly.
>
> Thanks,
>
> Jun
>
>
> On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <jb...@squareup.com>
> wrote:
>
> > So, does this indicate kafka (or the jvm itself) is not aggressively
> > closing file handles of deleted files? Is there a fix for this? Or is
> > there not likely anything to be done? What happens if the disk fills up
> > with file handles for phantom deleted files?
> >
> > Jason
> >
> >
> > On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <jc...@box.com> wrote:
> >
> > > It isn't uncommon if a process has an open file handle on a file that
> is
> > > deleted, the space is not freed until the handle is closed. So
> restarting
> > > the process that has a handle on the file would cause the space to be
> > freed
> > > also.
> > >
> > > You can troubleshoot that with lsof.
> > > Normally, I see 2-4 log segments deleted every hour in my brokers. I
> see
> > > log lines like this:
> > >
> > > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0] log.LogManager -
> > > Deleting log segment 00000000035434043157.kafka from <redacted topic>
> > >
> > > However, it seems like if I restart the broker, a massive amount of
> disk
> > > space is freed (without a corresponding flood of these log segment
> > deleted
> > > messages). Is there an explanation for this? Does kafka keep
> reference
> > to
> > > file segments around, and reuse them as needed or something? And then
> or
> > > restart, the references to those free segment files are dropped?
> > >
> > > Thoughts?
> > >
> > > This is with 0.7.2.
> > >
> > > Jason
> > >
> >
>
Re: large amount of disk space freed on restart
Posted by Jun Rao <ju...@gmail.com>.
Jason,
Kafka closes the handler of all delete files. Otherwise, the broker will
run out of file handler quickly.
Thanks,
Jun
On Wed, May 22, 2013 at 10:17 PM, Jason Rosenberg <jb...@squareup.com> wrote:
> So, does this indicate kafka (or the jvm itself) is not aggressively
> closing file handles of deleted files? Is there a fix for this? Or is
> there not likely anything to be done? What happens if the disk fills up
> with file handles for phantom deleted files?
>
> Jason
>
>
> On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <jc...@box.com> wrote:
>
> > It isn't uncommon if a process has an open file handle on a file that is
> > deleted, the space is not freed until the handle is closed. So restarting
> > the process that has a handle on the file would cause the space to be
> freed
> > also.
> >
> > You can troubleshoot that with lsof.
> > Normally, I see 2-4 log segments deleted every hour in my brokers. I see
> > log lines like this:
> >
> > 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0] log.LogManager -
> > Deleting log segment 00000000035434043157.kafka from <redacted topic>
> >
> > However, it seems like if I restart the broker, a massive amount of disk
> > space is freed (without a corresponding flood of these log segment
> deleted
> > messages). Is there an explanation for this? Does kafka keep reference
> to
> > file segments around, and reuse them as needed or something? And then or
> > restart, the references to those free segment files are dropped?
> >
> > Thoughts?
> >
> > This is with 0.7.2.
> >
> > Jason
> >
>
Re: large amount of disk space freed on restart
Posted by Jason Rosenberg <jb...@squareup.com>.
So, does this indicate kafka (or the jvm itself) is not aggressively
closing file handles of deleted files? Is there a fix for this? Or is
there not likely anything to be done? What happens if the disk fills up
with file handles for phantom deleted files?
Jason
On Wed, May 22, 2013 at 9:50 PM, Jonathan Creasy <jc...@box.com> wrote:
> It isn't uncommon if a process has an open file handle on a file that is
> deleted, the space is not freed until the handle is closed. So restarting
> the process that has a handle on the file would cause the space to be freed
> also.
>
> You can troubleshoot that with lsof.
> Normally, I see 2-4 log segments deleted every hour in my brokers. I see
> log lines like this:
>
> 2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0] log.LogManager -
> Deleting log segment 00000000035434043157.kafka from <redacted topic>
>
> However, it seems like if I restart the broker, a massive amount of disk
> space is freed (without a corresponding flood of these log segment deleted
> messages). Is there an explanation for this? Does kafka keep reference to
> file segments around, and reuse them as needed or something? And then or
> restart, the references to those free segment files are dropped?
>
> Thoughts?
>
> This is with 0.7.2.
>
> Jason
>
Re: large amount of disk space freed on restart
Posted by Jonathan Creasy <jc...@box.com>.
It isn't uncommon if a process has an open file handle on a file that is
deleted, the space is not freed until the handle is closed. So restarting
the process that has a handle on the file would cause the space to be freed
also.
You can troubleshoot that with lsof.
Normally, I see 2-4 log segments deleted every hour in my brokers. I see
log lines like this:
2013-05-23 04:40:06,857 INFO [kafka-logcleaner-0] log.LogManager -
Deleting log segment 00000000035434043157.kafka from <redacted topic>
However, it seems like if I restart the broker, a massive amount of disk
space is freed (without a corresponding flood of these log segment deleted
messages). Is there an explanation for this? Does kafka keep reference to
file segments around, and reuse them as needed or something? And then or
restart, the references to those free segment files are dropped?
Thoughts?
This is with 0.7.2.
Jason