flume-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Brock Noland <br...@cloudera.com>
Subject Re: file channel read performance impacted by write rate
Date Tue, 17 Dec 2013 17:51:53 GMT
On Mon, Nov 18, 2013 at 4:28 AM, Jan Van Besien <janvb@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.

Mime
View raw message