You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@flume.apache.org by Jan Van Besien <ja...@ngdata.com> on 2013/11/13 10:32:24 UTC
file channel read performance impacted by write rate
Hi,
I noticed that the rate by which sinks can read from a file channel, is
heavily dependant on the rate by which sources are writing into that
file channel.
It can be easily tested with the null sink and a source that writes
events one by one into the file channel.
If the source writes events one by one (at the maximum speed the file
channel can handle), the rate at the sink is easily more than 10 times
slower than if the source is not writing at all, or batching the writes.
I can understand that there is an impact, but the impact seems really
big.. I have a case here where the write rate in the file channel
(events are written one by one) is actually good enough, but the read
rate suffers so much that that becomes a bottleneck. I can solve it with
a memory channel in front such that the writes in the file channel are
done in batches, but that means I loose overall durability of the events.
Any insights on this?
Thanks,
Jan
Re: file channel read performance impacted by write rate
Posted by Jan Van Besien <ja...@ngdata.com>.
On 11/18/2013 11:28 AM, Jan Van Besien wrote:
> - thread dumps while the ingest was running and the null sink was enabled
After looking at the thread dumps myself, I did some profiling (yourkit
"monitor profiling"). It seems to suggest that about 40% of the time, it
is blocking on a monitor defined by the "synchronized" keyword in the
LogFile$Writer.put(ByteBuffer) method. That seems significant?
Jan
Re: file channel read performance impacted by write rate
Posted by Brock Noland <br...@cloudera.com>.
On Mon, Nov 18, 2013 at 4:28 AM, Jan Van Besien <ja...@ngdata.com> wrote:
> Hi,
>
> Sorry it took me a while to answer this. I compiled a small test case
> using only off the shelve flume components that shows what is going on.
>
and sorry it took even longer to get back to you. Thank you very much for
the detail information.
>
> The setup is a single agent with http source, null sink and file
> channel. I am using the default configuration as much as possible.
>
> The test goes as follows:
>
> - start the agent without sink
> - run a script that sends http requests in multiple threads to the http
> source (the script simply calls the url http://localhost:8080/?key=value
> over and over a gain, whereby value is a random string of 100 chars).
>
Note, this source will be writing a *single* event and then doing a commit
to the file channel which causes an fsync event to occur which is very
expensive. *If you want any kind of reasonable throughput you need to back
events at the source.*
Note you said you have *multiple threads* sending *single events*. This is
a recipe for low throughput. Looking at the thread dumps you can see this
actually taking place. For example below you can see two HTTP threads
performing puts and the null sink thread is waiting for access to the log.
Reasonable performance can only be obtained with file channel when the
source batches events.
2013-11-18 11:14:36
Full thread dump Java HotSpot(TM) 64-Bit Server VM (23.6-b04 mixed mode):
"1172445666@qtp-1032572545-2" prio=10 tid=0x00007fa2fc00d000 nid=0x2dfc
runnable [0x00007fa38c92c000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.FileDispatcherImpl.force0(Native Method)
at sun.nio.ch.FileDispatcherImpl.force(FileDispatcherImpl.java:75)
at sun.nio.ch.FileChannelImpl.force(FileChannelImpl.java:363)
at org.apache.flume.channel.file.LogFile$Writer.sync(LogFile.java:307)
- locked <0x00000000fffc80d0> (a
org.apache.flume.channel.file.LogFileV3$Writer)
at org.apache.flume.channel.file.Log.commit(Log.java:877)
at org.apache.flume.channel.file.Log.commitPut(Log.java:730)
at
org.apache.flume.channel.file.FileChannel$FileBackedTransaction.doCommit(FileChannel.java:567)
at
org.apache.flume.channel.BasicTransactionSemantics.commit(BasicTransactionSemantics.java:151)
at
org.apache.flume.channel.ChannelProcessor.processEventBatch(ChannelProcessor.java:192)
at
org.apache.flume.source.http.HTTPSource$FlumeHTTPServlet.doPost(HTTPSource.java:201)
"SinkRunner-PollingRunner-DefaultSinkProcessor" prio=10
tid=0x00007fa324002800 nid=0x2dfb waiting for monitor entry
[0x00007fa38d8d9000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.flume.channel.file.LogFile$Writer.take(LogFile.java:245)
- waiting to lock <0x00000000fffc80d0> (a
org.apache.flume.channel.file.LogFileV3$Writer)
at org.apache.flume.channel.file.Log.take(Log.java:657)
at
org.apache.flume.channel.file.FileChannel$FileBackedTransaction.doTake(FileChannel.java:537)
at
org.apache.flume.channel.BasicTransactionSemantics.take(BasicTransactionSemantics.java:113)
at
org.apache.flume.channel.BasicChannelSemantics.take(BasicChannelSemantics.java:95)
at org.apache.flume.sink.NullSink.process(NullSink.java:91)
at
org.apache.flume.sink.DefaultSinkProcessor.process(DefaultSinkProcessor.java:68)
at org.apache.flume.SinkRunner$PollingRunner.run(SinkRunner.java:147)
at java.lang.Thread.run(Thread.java:722)
"631412408@qtp-1032572545-0" prio=10 tid=0x00007fa310001000 nid=0x2df8
waiting for monitor entry [0x00007fa38d9d9000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.flume.channel.file.LogFile$Writer.put(LogFile.java:238)
- waiting to lock <0x00000000fffc80d0> (a
org.apache.flume.channel.file.LogFileV3$Writer)
at org.apache.flume.channel.file.Log.put(Log.java:614)
at
org.apache.flume.channel.file.FileChannel$FileBackedTransaction.doPut(FileChannel.java:482)
at
org.apache.flume.channel.BasicTransactionSemantics.put(BasicTransactionSemantics.java:93)
at
org.apache.flume.channel.BasicChannelSemantics.put(BasicChannelSemantics.java:80)
at
org.apache.flume.channel.ChannelProcessor.processEventBatch(ChannelProcessor.java:189)
at
org.apache.flume.source.http.HTTPSource$FlumeHTTPServlet.doPost(HTTPSource.java:201)
> - this script does about 100 requests per second on my machine. I leave
> it running for a while, such that the file channel contains about 20000
> events.
> - add the null sink to the configuration (around 11:14:33 in the log).
> - observe the logging of the null sink. You'll see in the log file that
> it takes more than 10 seconds per 1000 events (until about even 5000,
> around 11:15:33)
> - stop the http request generating script (i.e. no more writing in file
> channel)
> - observer the logging of the null sink: events 5000 until 20000 are all
> processed within a few seconds.
>
Right, because the null sink is not waiting on the HTTP threads which have
the lock on the log.
Re: file channel read performance impacted by write rate
Posted by Hari Shreedharan <hs...@cloudera.com>.
The only reason I can think of for reads being slower is the overwriteMap
in the FlumeEventQueue in which keys of many events are changed for takes
but for puts we just add the next key and insert it into the map.
On Tuesday, December 17, 2013, Brock Noland wrote:
> Hi,
>
> 1) You are only using a single disk for file channel and it looks like a
> single disk for both checkpoint and data directories therefore throughput
> is going to be extremely slow.
> 2) I asked for 8-10 thread dumps of the whole JVM but got two thread dumps
> of two random threads. If you don't want to share this info on-list, please
> send it to me directly...but I will need a bunch of thread dumps to debug
> thing.
>
> Brock
>
>
> On Tue, Dec 17, 2013 at 9:32 AM, Shangan Chen <ch...@gmail.com>wrote:
>
> the attachment flume.conf is channel and sink config, dumps.txt is thread
> dumps.
> channel type "dual" is a channel type I developped to utilize the merits
> of memory channel and filechannel. when the volume is not quite big, I use
> memory channel, when the size of events reach to a percentage of the memory
> channel capacity, it switch to the filechannel, when volume decrease switch
> to memory again.
>
> thanks for looking into this.
>
>
> On Tue, Dec 17, 2013 at 8:54 PM, Brock Noland <br...@cloudera.com> wrote:
>
> Can you take and share 8-10 thread dumps while the sink is taking events
> "slowly"?
>
> Can you share your machine and file channel configuration?
> On Dec 17, 2013 6:28 AM, "Shangan Chen" <ch...@gmail.com> wrote:
>
> we face the same problem, performance of taking events from channel is a
> severe bottleneck. When there're less events in channel, problem does not
> alleviate. following is a log of the metrics of writing to hdfs, writing to
> 5 files with a batchsize of 200000, take cost the most of the total time.
>
>
> 17 十二月 2013 18:49:28,056 INFO
> [SinkRunner-PollingRunner-DefaultSinkProcessor]
> (org.apache.flume.sink.hdfs.HDFSEventSink.process:489) -
> HdfsSink-TIME-STAT sink[sink_hdfs_b] writers[5] eventcount[200000]
> all[44513] take[38197] append[5647] sync[17] getFilenameTime[371]
>
>
>
>
>
> On Mon, Nov 25, 2013 at 4:46 PM, Jan Van Besien <ja...@ngdata.com> wrote:
>
> Hi,
>
> Is anybody still looking into this question?
>
> Should I log it in jira such that somebody can look into it later?
>
> thanks,
> Jan
>
>
>
> On 11/18/2013 11:28 AM, Jan Van Besien wrote:
> > Hi,
> >
> > Sorry it took me a while to answer this. I compiled a small test case
> > using only off the shelve flume components that shows what is going on.
> >
> > The setup is a single agent with http source, null sink and file
> > channel. I am using the default configuration as much as possible.
> >
> > The test goes as follows:
> >
> > - start the agent without sink
> > - run a script that sends http requests in multiple threads to the http
> > source (the script simply calls the url http://localhost:8080/?key=value
> > over and over a gain, whereby value is a random string of 100 chars).
> > - this script does about 100 requests per second on my machine. I leave
> > it running for a while, such that the file channel contains about 20000
> > events.
> > - add the null sink to the configuration (around 11:14:33 in the log).
> > - observe the logging of the null sink. You'll see in the log file that
> > it takes more than 10 seconds per 1000 events (until about even 5000,
> > around 11:15:33)
> > - stop the http request generating script (i.e. no more writing in file
> > channel)
> > - observer the logging of the null sink: events 5000 until 20000 are all
> > processed within a few seconds.
> >
> > In the attachment:
> > - flume log
> > - thread dumps while the ingest was running and the null sink was enabled
> > - config (agent1.conf)
> >
> > I also tried with more sinks (4), see agent2.conf. The results are the
> same.
> >
> > Thanks for looking into this,
> > Jan
> >
> >
> > On 11/14/2013 05:08 PM, Brock Noland wrote:
> >> On Thu, Nov 14, 2013 at 2:50 AM, Jan Van Besien <ja
>
> --
> Apache MRUnit - Unit testing MapReduce - http://mrunit.apache.org
>
Re: file channel read performance impacted by write rate
Posted by Brock Noland <br...@cloudera.com>.
Hi,
1) You are only using a single disk for file channel and it looks like a
single disk for both checkpoint and data directories therefore throughput
is going to be extremely slow.
2) I asked for 8-10 thread dumps of the whole JVM but got two thread dumps
of two random threads. If you don't want to share this info on-list, please
send it to me directly...but I will need a bunch of thread dumps to debug
thing.
Brock
On Tue, Dec 17, 2013 at 9:32 AM, Shangan Chen <ch...@gmail.com>wrote:
> the attachment flume.conf is channel and sink config, dumps.txt is thread
> dumps.
> channel type "dual" is a channel type I developped to utilize the merits
> of memory channel and filechannel. when the volume is not quite big, I use
> memory channel, when the size of events reach to a percentage of the memory
> channel capacity, it switch to the filechannel, when volume decrease switch
> to memory again.
>
> thanks for looking into this.
>
>
> On Tue, Dec 17, 2013 at 8:54 PM, Brock Noland <br...@cloudera.com> wrote:
>
>> Can you take and share 8-10 thread dumps while the sink is taking events
>> "slowly"?
>>
>> Can you share your machine and file channel configuration?
>> On Dec 17, 2013 6:28 AM, "Shangan Chen" <ch...@gmail.com> wrote:
>>
>>> we face the same problem, performance of taking events from channel is a
>>> severe bottleneck. When there're less events in channel, problem does not
>>> alleviate. following is a log of the metrics of writing to hdfs, writing to
>>> 5 files with a batchsize of 200000, take cost the most of the total time.
>>>
>>>
>>> 17 十二月 2013 18:49:28,056 INFO
>>> [SinkRunner-PollingRunner-DefaultSinkProcessor]
>>> (org.apache.flume.sink.hdfs.HDFSEventSink.process:489) -
>>> HdfsSink-TIME-STAT sink[sink_hdfs_b] writers[5] eventcount[200000]
>>> all[44513] take[38197] append[5647] sync[17] getFilenameTime[371]
>>>
>>>
>>>
>>>
>>>
>>> On Mon, Nov 25, 2013 at 4:46 PM, Jan Van Besien <ja...@ngdata.com>wrote:
>>>
>>>> Hi,
>>>>
>>>> Is anybody still looking into this question?
>>>>
>>>> Should I log it in jira such that somebody can look into it later?
>>>>
>>>> thanks,
>>>> Jan
>>>>
>>>>
>>>>
>>>> On 11/18/2013 11:28 AM, Jan Van Besien wrote:
>>>> > Hi,
>>>> >
>>>> > Sorry it took me a while to answer this. I compiled a small test case
>>>> > using only off the shelve flume components that shows what is going
>>>> on.
>>>> >
>>>> > The setup is a single agent with http source, null sink and file
>>>> > channel. I am using the default configuration as much as possible.
>>>> >
>>>> > The test goes as follows:
>>>> >
>>>> > - start the agent without sink
>>>> > - run a script that sends http requests in multiple threads to the
>>>> http
>>>> > source (the script simply calls the url
>>>> http://localhost:8080/?key=value
>>>> > over and over a gain, whereby value is a random string of 100 chars).
>>>> > - this script does about 100 requests per second on my machine. I
>>>> leave
>>>> > it running for a while, such that the file channel contains about
>>>> 20000
>>>> > events.
>>>> > - add the null sink to the configuration (around 11:14:33 in the log).
>>>> > - observe the logging of the null sink. You'll see in the log file
>>>> that
>>>> > it takes more than 10 seconds per 1000 events (until about even 5000,
>>>> > around 11:15:33)
>>>> > - stop the http request generating script (i.e. no more writing in
>>>> file
>>>> > channel)
>>>> > - observer the logging of the null sink: events 5000 until 20000 are
>>>> all
>>>> > processed within a few seconds.
>>>> >
>>>> > In the attachment:
>>>> > - flume log
>>>> > - thread dumps while the ingest was running and the null sink was
>>>> enabled
>>>> > - config (agent1.conf)
>>>> >
>>>> > I also tried with more sinks (4), see agent2.conf. The results are
>>>> the same.
>>>> >
>>>> > Thanks for looking into this,
>>>> > Jan
>>>> >
>>>> >
>>>> > On 11/14/2013 05:08 PM, Brock Noland wrote:
>>>> >> On Thu, Nov 14, 2013 at 2:50 AM, Jan Van Besien <janvb@ngdata.com
>>>> >> <ma...@ngdata.com>> wrote:
>>>> >>
>>>> >> On 11/13/2013 03:04 PM, Brock Noland wrote:
>>>> >> > The file channel uses a WAL which sits on disk. Each time an
>>>> >> event is
>>>> >> > committed an fsync is called to ensure that data is durable.
>>>> Without
>>>> >> > this fsync there is no durability guarantee. More details
>>>> here:
>>>> >> >
>>>> https://blogs.apache.org/flume/entry/apache_flume_filechannel
>>>> >>
>>>> >> Yes indeed. I was just not expecting the performance impact to
>>>> be
>>>> >> that big.
>>>> >>
>>>> >>
>>>> >> > The issue is that when the source is committing one-by-one
>>>> it's
>>>> >> > consuming the disk doing an fsync for each event. I would
>>>> find a
>>>> >> way to
>>>> >> > batch up the requests so they are not written one-by-one or
>>>> use
>>>> >> multiple
>>>> >> > disks for the file channel.
>>>> >>
>>>> >> I am already using multiple disks for the channel (4).
>>>> >>
>>>> >>
>>>> >> Can you share your configuration?
>>>> >>
>>>> >> Batching the
>>>> >> requests is indeed what I am doing to prevent the filechannel
>>>> to be the
>>>> >> bottleneck (using a flume agent with a memory channel in front
>>>> of the
>>>> >> agent with the file channel), but it inheritely means that I
>>>> loose
>>>> >> end-to-end durability because events are buffered in memory
>>>> before being
>>>> >> flushed to disk.
>>>> >>
>>>> >>
>>>> >> I would be curious to know though if you doubled the sinks if that
>>>> would
>>>> >> give more time to readers. Could you take three-four thread dumps of
>>>> the
>>>> >> JVM while it's in this state and share them?
>>>> >>
>>>> >
>>>>
>>>>
>>>
>>>
>>> --
>>> have a good day!
>>> chenshang'an
>>>
>>>
>
>
> --
> have a good day!
> chenshang'an
>
>
--
Apache MRUnit - Unit testing MapReduce - http://mrunit.apache.org
Re: file channel read performance impacted by write rate
Posted by Shangan Chen <ch...@gmail.com>.
the attachment flume.conf is channel and sink config, dumps.txt is thread
dumps.
channel type "dual" is a channel type I developped to utilize the merits of
memory channel and filechannel. when the volume is not quite big, I use
memory channel, when the size of events reach to a percentage of the memory
channel capacity, it switch to the filechannel, when volume decrease switch
to memory again.
thanks for looking into this.
On Tue, Dec 17, 2013 at 8:54 PM, Brock Noland <br...@cloudera.com> wrote:
> Can you take and share 8-10 thread dumps while the sink is taking events
> "slowly"?
>
> Can you share your machine and file channel configuration?
> On Dec 17, 2013 6:28 AM, "Shangan Chen" <ch...@gmail.com> wrote:
>
>> we face the same problem, performance of taking events from channel is a
>> severe bottleneck. When there're less events in channel, problem does not
>> alleviate. following is a log of the metrics of writing to hdfs, writing to
>> 5 files with a batchsize of 200000, take cost the most of the total time.
>>
>>
>> 17 十二月 2013 18:49:28,056 INFO
>> [SinkRunner-PollingRunner-DefaultSinkProcessor]
>> (org.apache.flume.sink.hdfs.HDFSEventSink.process:489) -
>> HdfsSink-TIME-STAT sink[sink_hdfs_b] writers[5] eventcount[200000]
>> all[44513] take[38197] append[5647] sync[17] getFilenameTime[371]
>>
>>
>>
>>
>>
>> On Mon, Nov 25, 2013 at 4:46 PM, Jan Van Besien <ja...@ngdata.com> wrote:
>>
>>> Hi,
>>>
>>> Is anybody still looking into this question?
>>>
>>> Should I log it in jira such that somebody can look into it later?
>>>
>>> thanks,
>>> Jan
>>>
>>>
>>>
>>> On 11/18/2013 11:28 AM, Jan Van Besien wrote:
>>> > Hi,
>>> >
>>> > Sorry it took me a while to answer this. I compiled a small test case
>>> > using only off the shelve flume components that shows what is going on.
>>> >
>>> > The setup is a single agent with http source, null sink and file
>>> > channel. I am using the default configuration as much as possible.
>>> >
>>> > The test goes as follows:
>>> >
>>> > - start the agent without sink
>>> > - run a script that sends http requests in multiple threads to the http
>>> > source (the script simply calls the url
>>> http://localhost:8080/?key=value
>>> > over and over a gain, whereby value is a random string of 100 chars).
>>> > - this script does about 100 requests per second on my machine. I leave
>>> > it running for a while, such that the file channel contains about 20000
>>> > events.
>>> > - add the null sink to the configuration (around 11:14:33 in the log).
>>> > - observe the logging of the null sink. You'll see in the log file that
>>> > it takes more than 10 seconds per 1000 events (until about even 5000,
>>> > around 11:15:33)
>>> > - stop the http request generating script (i.e. no more writing in file
>>> > channel)
>>> > - observer the logging of the null sink: events 5000 until 20000 are
>>> all
>>> > processed within a few seconds.
>>> >
>>> > In the attachment:
>>> > - flume log
>>> > - thread dumps while the ingest was running and the null sink was
>>> enabled
>>> > - config (agent1.conf)
>>> >
>>> > I also tried with more sinks (4), see agent2.conf. The results are the
>>> same.
>>> >
>>> > Thanks for looking into this,
>>> > Jan
>>> >
>>> >
>>> > On 11/14/2013 05:08 PM, Brock Noland wrote:
>>> >> On Thu, Nov 14, 2013 at 2:50 AM, Jan Van Besien <janvb@ngdata.com
>>> >> <ma...@ngdata.com>> wrote:
>>> >>
>>> >> On 11/13/2013 03:04 PM, Brock Noland wrote:
>>> >> > The file channel uses a WAL which sits on disk. Each time an
>>> >> event is
>>> >> > committed an fsync is called to ensure that data is durable.
>>> Without
>>> >> > this fsync there is no durability guarantee. More details
>>> here:
>>> >> > https://blogs.apache.org/flume/entry/apache_flume_filechannel
>>> >>
>>> >> Yes indeed. I was just not expecting the performance impact to be
>>> >> that big.
>>> >>
>>> >>
>>> >> > The issue is that when the source is committing one-by-one
>>> it's
>>> >> > consuming the disk doing an fsync for each event. I would
>>> find a
>>> >> way to
>>> >> > batch up the requests so they are not written one-by-one or
>>> use
>>> >> multiple
>>> >> > disks for the file channel.
>>> >>
>>> >> I am already using multiple disks for the channel (4).
>>> >>
>>> >>
>>> >> Can you share your configuration?
>>> >>
>>> >> Batching the
>>> >> requests is indeed what I am doing to prevent the filechannel to
>>> be the
>>> >> bottleneck (using a flume agent with a memory channel in front
>>> of the
>>> >> agent with the file channel), but it inheritely means that I
>>> loose
>>> >> end-to-end durability because events are buffered in memory
>>> before being
>>> >> flushed to disk.
>>> >>
>>> >>
>>> >> I would be curious to know though if you doubled the sinks if that
>>> would
>>> >> give more time to readers. Could you take three-four thread dumps of
>>> the
>>> >> JVM while it's in this state and share them?
>>> >>
>>> >
>>>
>>>
>>
>>
>> --
>> have a good day!
>> chenshang'an
>>
>>
--
have a good day!
chenshang'an
Re: file channel read performance impacted by write rate
Posted by Brock Noland <br...@cloudera.com>.
Can you take and share 8-10 thread dumps while the sink is taking events
"slowly"?
Can you share your machine and file channel configuration?
On Dec 17, 2013 6:28 AM, "Shangan Chen" <ch...@gmail.com> wrote:
> we face the same problem, performance of taking events from channel is a
> severe bottleneck. When there're less events in channel, problem does not
> alleviate. following is a log of the metrics of writing to hdfs, writing to
> 5 files with a batchsize of 200000, take cost the most of the total time.
>
>
> 17 十二月 2013 18:49:28,056 INFO
> [SinkRunner-PollingRunner-DefaultSinkProcessor]
> (org.apache.flume.sink.hdfs.HDFSEventSink.process:489) -
> HdfsSink-TIME-STAT sink[sink_hdfs_b] writers[5] eventcount[200000]
> all[44513] take[38197] append[5647] sync[17] getFilenameTime[371]
>
>
>
>
>
> On Mon, Nov 25, 2013 at 4:46 PM, Jan Van Besien <ja...@ngdata.com> wrote:
>
>> Hi,
>>
>> Is anybody still looking into this question?
>>
>> Should I log it in jira such that somebody can look into it later?
>>
>> thanks,
>> Jan
>>
>>
>>
>> On 11/18/2013 11:28 AM, Jan Van Besien wrote:
>> > Hi,
>> >
>> > Sorry it took me a while to answer this. I compiled a small test case
>> > using only off the shelve flume components that shows what is going on.
>> >
>> > The setup is a single agent with http source, null sink and file
>> > channel. I am using the default configuration as much as possible.
>> >
>> > The test goes as follows:
>> >
>> > - start the agent without sink
>> > - run a script that sends http requests in multiple threads to the http
>> > source (the script simply calls the url
>> http://localhost:8080/?key=value
>> > over and over a gain, whereby value is a random string of 100 chars).
>> > - this script does about 100 requests per second on my machine. I leave
>> > it running for a while, such that the file channel contains about 20000
>> > events.
>> > - add the null sink to the configuration (around 11:14:33 in the log).
>> > - observe the logging of the null sink. You'll see in the log file that
>> > it takes more than 10 seconds per 1000 events (until about even 5000,
>> > around 11:15:33)
>> > - stop the http request generating script (i.e. no more writing in file
>> > channel)
>> > - observer the logging of the null sink: events 5000 until 20000 are all
>> > processed within a few seconds.
>> >
>> > In the attachment:
>> > - flume log
>> > - thread dumps while the ingest was running and the null sink was
>> enabled
>> > - config (agent1.conf)
>> >
>> > I also tried with more sinks (4), see agent2.conf. The results are the
>> same.
>> >
>> > Thanks for looking into this,
>> > Jan
>> >
>> >
>> > On 11/14/2013 05:08 PM, Brock Noland wrote:
>> >> On Thu, Nov 14, 2013 at 2:50 AM, Jan Van Besien <janvb@ngdata.com
>> >> <ma...@ngdata.com>> wrote:
>> >>
>> >> On 11/13/2013 03:04 PM, Brock Noland wrote:
>> >> > The file channel uses a WAL which sits on disk. Each time an
>> >> event is
>> >> > committed an fsync is called to ensure that data is durable.
>> Without
>> >> > this fsync there is no durability guarantee. More details here:
>> >> > https://blogs.apache.org/flume/entry/apache_flume_filechannel
>> >>
>> >> Yes indeed. I was just not expecting the performance impact to be
>> >> that big.
>> >>
>> >>
>> >> > The issue is that when the source is committing one-by-one it's
>> >> > consuming the disk doing an fsync for each event. I would
>> find a
>> >> way to
>> >> > batch up the requests so they are not written one-by-one or use
>> >> multiple
>> >> > disks for the file channel.
>> >>
>> >> I am already using multiple disks for the channel (4).
>> >>
>> >>
>> >> Can you share your configuration?
>> >>
>> >> Batching the
>> >> requests is indeed what I am doing to prevent the filechannel to
>> be the
>> >> bottleneck (using a flume agent with a memory channel in front of
>> the
>> >> agent with the file channel), but it inheritely means that I loose
>> >> end-to-end durability because events are buffered in memory
>> before being
>> >> flushed to disk.
>> >>
>> >>
>> >> I would be curious to know though if you doubled the sinks if that
>> would
>> >> give more time to readers. Could you take three-four thread dumps of
>> the
>> >> JVM while it's in this state and share them?
>> >>
>> >
>>
>>
>
>
> --
> have a good day!
> chenshang'an
>
>
Re: file channel read performance impacted by write rate
Posted by Shangan Chen <ch...@gmail.com>.
we face the same problem, performance of taking events from channel is a
severe bottleneck. When there're less events in channel, problem does not
alleviate. following is a log of the metrics of writing to hdfs, writing to
5 files with a batchsize of 200000, take cost the most of the total time.
17 十二月 2013 18:49:28,056 INFO
[SinkRunner-PollingRunner-DefaultSinkProcessor]
(org.apache.flume.sink.hdfs.HDFSEventSink.process:489) -
HdfsSink-TIME-STAT sink[sink_hdfs_b] writers[5] eventcount[200000]
all[44513] take[38197] append[5647] sync[17] getFilenameTime[371]
On Mon, Nov 25, 2013 at 4:46 PM, Jan Van Besien <ja...@ngdata.com> wrote:
> Hi,
>
> Is anybody still looking into this question?
>
> Should I log it in jira such that somebody can look into it later?
>
> thanks,
> Jan
>
>
>
> On 11/18/2013 11:28 AM, Jan Van Besien wrote:
> > Hi,
> >
> > Sorry it took me a while to answer this. I compiled a small test case
> > using only off the shelve flume components that shows what is going on.
> >
> > The setup is a single agent with http source, null sink and file
> > channel. I am using the default configuration as much as possible.
> >
> > The test goes as follows:
> >
> > - start the agent without sink
> > - run a script that sends http requests in multiple threads to the http
> > source (the script simply calls the url http://localhost:8080/?key=value
> > over and over a gain, whereby value is a random string of 100 chars).
> > - this script does about 100 requests per second on my machine. I leave
> > it running for a while, such that the file channel contains about 20000
> > events.
> > - add the null sink to the configuration (around 11:14:33 in the log).
> > - observe the logging of the null sink. You'll see in the log file that
> > it takes more than 10 seconds per 1000 events (until about even 5000,
> > around 11:15:33)
> > - stop the http request generating script (i.e. no more writing in file
> > channel)
> > - observer the logging of the null sink: events 5000 until 20000 are all
> > processed within a few seconds.
> >
> > In the attachment:
> > - flume log
> > - thread dumps while the ingest was running and the null sink was enabled
> > - config (agent1.conf)
> >
> > I also tried with more sinks (4), see agent2.conf. The results are the
> same.
> >
> > Thanks for looking into this,
> > Jan
> >
> >
> > On 11/14/2013 05:08 PM, Brock Noland wrote:
> >> On Thu, Nov 14, 2013 at 2:50 AM, Jan Van Besien <janvb@ngdata.com
> >> <ma...@ngdata.com>> wrote:
> >>
> >> On 11/13/2013 03:04 PM, Brock Noland wrote:
> >> > The file channel uses a WAL which sits on disk. Each time an
> >> event is
> >> > committed an fsync is called to ensure that data is durable.
> Without
> >> > this fsync there is no durability guarantee. More details here:
> >> > https://blogs.apache.org/flume/entry/apache_flume_filechannel
> >>
> >> Yes indeed. I was just not expecting the performance impact to be
> >> that big.
> >>
> >>
> >> > The issue is that when the source is committing one-by-one it's
> >> > consuming the disk doing an fsync for each event. I would find
> a
> >> way to
> >> > batch up the requests so they are not written one-by-one or use
> >> multiple
> >> > disks for the file channel.
> >>
> >> I am already using multiple disks for the channel (4).
> >>
> >>
> >> Can you share your configuration?
> >>
> >> Batching the
> >> requests is indeed what I am doing to prevent the filechannel to
> be the
> >> bottleneck (using a flume agent with a memory channel in front of
> the
> >> agent with the file channel), but it inheritely means that I loose
> >> end-to-end durability because events are buffered in memory before
> being
> >> flushed to disk.
> >>
> >>
> >> I would be curious to know though if you doubled the sinks if that would
> >> give more time to readers. Could you take three-four thread dumps of the
> >> JVM while it's in this state and share them?
> >>
> >
>
>
--
have a good day!
chenshang'an
Re: file channel read performance impacted by write rate
Posted by Jan Van Besien <ja...@ngdata.com>.
Hi,
Is anybody still looking into this question?
Should I log it in jira such that somebody can look into it later?
thanks,
Jan
On 11/18/2013 11:28 AM, Jan Van Besien wrote:
> Hi,
>
> Sorry it took me a while to answer this. I compiled a small test case
> using only off the shelve flume components that shows what is going on.
>
> The setup is a single agent with http source, null sink and file
> channel. I am using the default configuration as much as possible.
>
> The test goes as follows:
>
> - start the agent without sink
> - run a script that sends http requests in multiple threads to the http
> source (the script simply calls the url http://localhost:8080/?key=value
> over and over a gain, whereby value is a random string of 100 chars).
> - this script does about 100 requests per second on my machine. I leave
> it running for a while, such that the file channel contains about 20000
> events.
> - add the null sink to the configuration (around 11:14:33 in the log).
> - observe the logging of the null sink. You'll see in the log file that
> it takes more than 10 seconds per 1000 events (until about even 5000,
> around 11:15:33)
> - stop the http request generating script (i.e. no more writing in file
> channel)
> - observer the logging of the null sink: events 5000 until 20000 are all
> processed within a few seconds.
>
> In the attachment:
> - flume log
> - thread dumps while the ingest was running and the null sink was enabled
> - config (agent1.conf)
>
> I also tried with more sinks (4), see agent2.conf. The results are the same.
>
> Thanks for looking into this,
> Jan
>
>
> On 11/14/2013 05:08 PM, Brock Noland wrote:
>> On Thu, Nov 14, 2013 at 2:50 AM, Jan Van Besien <janvb@ngdata.com
>> <ma...@ngdata.com>> wrote:
>>
>> On 11/13/2013 03:04 PM, Brock Noland wrote:
>> > The file channel uses a WAL which sits on disk. Each time an
>> event is
>> > committed an fsync is called to ensure that data is durable. Without
>> > this fsync there is no durability guarantee. More details here:
>> > https://blogs.apache.org/flume/entry/apache_flume_filechannel
>>
>> Yes indeed. I was just not expecting the performance impact to be
>> that big.
>>
>>
>> > The issue is that when the source is committing one-by-one it's
>> > consuming the disk doing an fsync for each event. I would find a
>> way to
>> > batch up the requests so they are not written one-by-one or use
>> multiple
>> > disks for the file channel.
>>
>> I am already using multiple disks for the channel (4).
>>
>>
>> Can you share your configuration?
>>
>> Batching the
>> requests is indeed what I am doing to prevent the filechannel to be the
>> bottleneck (using a flume agent with a memory channel in front of the
>> agent with the file channel), but it inheritely means that I loose
>> end-to-end durability because events are buffered in memory before being
>> flushed to disk.
>>
>>
>> I would be curious to know though if you doubled the sinks if that would
>> give more time to readers. Could you take three-four thread dumps of the
>> JVM while it's in this state and share them?
>>
>
Re: file channel read performance impacted by write rate
Posted by Jan Van Besien <ja...@ngdata.com>.
Hi,
Sorry it took me a while to answer this. I compiled a small test case
using only off the shelve flume components that shows what is going on.
The setup is a single agent with http source, null sink and file
channel. I am using the default configuration as much as possible.
The test goes as follows:
- start the agent without sink
- run a script that sends http requests in multiple threads to the http
source (the script simply calls the url http://localhost:8080/?key=value
over and over a gain, whereby value is a random string of 100 chars).
- this script does about 100 requests per second on my machine. I leave
it running for a while, such that the file channel contains about 20000
events.
- add the null sink to the configuration (around 11:14:33 in the log).
- observe the logging of the null sink. You'll see in the log file that
it takes more than 10 seconds per 1000 events (until about even 5000,
around 11:15:33)
- stop the http request generating script (i.e. no more writing in file
channel)
- observer the logging of the null sink: events 5000 until 20000 are all
processed within a few seconds.
In the attachment:
- flume log
- thread dumps while the ingest was running and the null sink was enabled
- config (agent1.conf)
I also tried with more sinks (4), see agent2.conf. The results are the same.
Thanks for looking into this,
Jan
On 11/14/2013 05:08 PM, Brock Noland wrote:
> On Thu, Nov 14, 2013 at 2:50 AM, Jan Van Besien <janvb@ngdata.com
> <ma...@ngdata.com>> wrote:
>
> On 11/13/2013 03:04 PM, Brock Noland wrote:
> > The file channel uses a WAL which sits on disk. Each time an
> event is
> > committed an fsync is called to ensure that data is durable. Without
> > this fsync there is no durability guarantee. More details here:
> > https://blogs.apache.org/flume/entry/apache_flume_filechannel
>
> Yes indeed. I was just not expecting the performance impact to be
> that big.
>
>
> > The issue is that when the source is committing one-by-one it's
> > consuming the disk doing an fsync for each event. I would find a
> way to
> > batch up the requests so they are not written one-by-one or use
> multiple
> > disks for the file channel.
>
> I am already using multiple disks for the channel (4).
>
>
> Can you share your configuration?
>
> Batching the
> requests is indeed what I am doing to prevent the filechannel to be the
> bottleneck (using a flume agent with a memory channel in front of the
> agent with the file channel), but it inheritely means that I loose
> end-to-end durability because events are buffered in memory before being
> flushed to disk.
>
>
> I would be curious to know though if you doubled the sinks if that would
> give more time to readers. Could you take three-four thread dumps of the
> JVM while it's in this state and share them?
>
Re: file channel read performance impacted by write rate
Posted by Brock Noland <br...@cloudera.com>.
On Thu, Nov 14, 2013 at 2:50 AM, Jan Van Besien <ja...@ngdata.com> wrote:
> On 11/13/2013 03:04 PM, Brock Noland wrote:
> > The file channel uses a WAL which sits on disk. Each time an event is
> > committed an fsync is called to ensure that data is durable. Without
> > this fsync there is no durability guarantee. More details here:
> > https://blogs.apache.org/flume/entry/apache_flume_filechannel
>
> Yes indeed. I was just not expecting the performance impact to be that big.
> > The issue is that when the source is committing one-by-one it's
> > consuming the disk doing an fsync for each event. I would find a way to
> > batch up the requests so they are not written one-by-one or use multiple
> > disks for the file channel.
>
> I am already using multiple disks for the channel (4).
Can you share your configuration?
> Batching the
> requests is indeed what I am doing to prevent the filechannel to be the
> bottleneck (using a flume agent with a memory channel in front of the
> agent with the file channel), but it inheritely means that I loose
> end-to-end durability because events are buffered in memory before being
> flushed to disk.
>
I would be curious to know though if you doubled the sinks if that would
give more time to readers. Could you take three-four thread dumps of the
JVM while it's in this state and share them?
Re: file channel read performance impacted by write rate
Posted by Jan Van Besien <ja...@ngdata.com>.
On 11/13/2013 03:04 PM, Brock Noland wrote:
> The file channel uses a WAL which sits on disk. Each time an event is
> committed an fsync is called to ensure that data is durable. Without
> this fsync there is no durability guarantee. More details here:
> https://blogs.apache.org/flume/entry/apache_flume_filechannel
Yes indeed. I was just not expecting the performance impact to be that big.
> The issue is that when the source is committing one-by-one it's
> consuming the disk doing an fsync for each event. I would find a way to
> batch up the requests so they are not written one-by-one or use multiple
> disks for the file channel.
I am already using multiple disks for the channel (4). Batching the
requests is indeed what I am doing to prevent the filechannel to be the
bottleneck (using a flume agent with a memory channel in front of the
agent with the file channel), but it inheritely means that I loose
end-to-end durability because events are buffered in memory before being
flushed to disk.
thanks,
Jan
Re: file channel read performance impacted by write rate
Posted by Brock Noland <br...@cloudera.com>.
Hi,
The file channel uses a WAL which sits on disk. Each time an event is
committed an fsync is called to ensure that data is durable. Without this
fsync there is no durability guarantee. More details here:
https://blogs.apache.org/flume/entry/apache_flume_filechannel
The issue is that when the source is committing one-by-one it's consuming
the disk doing an fsync for each event. I would find a way to batch up the
requests so they are not written one-by-one or use multiple disks for the
file channel.
Brock
On Wed, Nov 13, 2013 at 3:32 AM, Jan Van Besien <ja...@ngdata.com> wrote:
> Hi,
>
> I noticed that the rate by which sinks can read from a file channel, is
> heavily dependant on the rate by which sources are writing into that
> file channel.
>
> It can be easily tested with the null sink and a source that writes
> events one by one into the file channel.
>
> If the source writes events one by one (at the maximum speed the file
> channel can handle), the rate at the sink is easily more than 10 times
> slower than if the source is not writing at all, or batching the writes.
>
> I can understand that there is an impact, but the impact seems really
> big.. I have a case here where the write rate in the file channel
> (events are written one by one) is actually good enough, but the read
> rate suffers so much that that becomes a bottleneck. I can solve it with
> a memory channel in front such that the writes in the file channel are
> done in batches, but that means I loose overall durability of the events.
>
> Any insights on this?
>
> Thanks,
> Jan
>
--
Apache MRUnit - Unit testing MapReduce - http://mrunit.apache.org