Fluency - Yet another fluent logger

1.
Fluency Yet another ﬂuentlogger Mitsunori Komatsu

2.
About me • MitsunoriKomatsu,   Software engineer • github:komamitsu  msgpack-java  (jackson-dataformat-msgpack),  ﬂuent-logger-java,  digdag,  :

3.
Today’s talk • What'sFluency? • Internal design • Performance and proﬁling • Future improvements

4.
Fluentd

5.
What’s Fluency? • Yetanother fluent-logger-java  (https://github.com/komamitsu/fluency) • 3x 4x faster than fluent-logger using PackedForward format • Easy to extend • Many features  (Async flush, HB, Failover, Ack response) • Used in LINE, Treasure Data, kafka-fluentd-consumer

6.
Internal design • Asynchronousﬂushing • Buffering PackedForward format data

7.
Async flushing Application FluencyBuffer FluentdFlusher emit(event:A) append(event:A) emit(event:B) append(event:B) store events as MessagePack flush send(event:[A, B]) emit(event:C) append(event:C) flush invoked repeatedly PackedForward format close close force flush emit(event:D) append(event:D) send(event:[C,D]) event:C isn’t ready for flush event:A,B are ready for flush terminate thread

8.

9.

10.

11.

12.

13.

14.

15.
Buffering events tag: aaa, time:100, {name: a_0} Buffer pool retention buffers ﬂushable buffers Fluentd emit event acquire buffer

16.
Buffering events tag: bbb, time:101, {name: b_0} Buffer pool time: 100, {name: a_0} retention buffers ﬂushable buffers tag: aaa Fluentd emit event acquire buffer

17.
Buffering events tag: ccc, time:102, {name: c_0} Buffer pool time: 100, {name: a_0} time: 101, {name: b_0} retention buffers ﬂushable buffers tag: aaa tag: bbb Fluentd emit event acquire buffer

18.
Buffering events tag: aaa, time:110, {name: a_1} Buffer pool time: 100, {name: a_0} time: 101, {name: b_0} time: 102, {name: c_0} retention buffers ﬂushable buffers tag: aaa tag: bbb tag: ccc Fluentd emit event

19.
Buffering events tag: aaa, time:120, {name: a_2} Buffer pool time: 100, {name: a_0} time: 110, {name: a_1} time: 101, {name: b_0} time: 102, {name: c_0} retention buffers ﬂushable buffers tag: aaa tag: bbb tag: ccc Fluentd emit event expand buffer

20.
Buffering events tag: bbb, time:111, {name: b_1} : : Buffer pool time: 100, {name: a_0} time: 110, {name: a_1} time: 120, {name: a_2} time: 101, {name: b_0} time: 102, {name: c_0} retention buffers ﬂushable buffers tag: aaa tag: bbb tag: ccc Fluentd emit event

21.
Buffering events tag: aaa, time:200, {name: a_0} Buffer pool time: 100, {name: a_0} time: 110, {name: a_1} time: 120, {name: a_2} time: 130, {name: a_3} time: 101, {name: b_0} time: 111, {name: b_1} time: 121, {name: b_2} time: 131, {name: b_3} time: 102, {name: c_0} time: 112, {name: c_1} retention buffers ﬂushable buffers tag: aaa tag: bbb tag: ccc Fluentd emit event move buffers (zero copy)

22.
tag: aaa Buffering events tag:ccc, time: 122, {name: c_2} Buffer pool time: 200, {name: a_0} time: 102, {name: c_0} time: 112, {name: c_1} retention buffers ﬂushable buffers tag: aaa tag: ccc time: 100, {name: a_0} time: 110, {name: a_1} time: 120, {name: a_2} time: 130, {name: a_3} Fluentd tag: bbb time: 101, {name: b_0} time: 111, {name: b_1} time: 121, {name: b_2} time: 131, {name: b_3} emit event expand buffer send buffer return buffer (after sending) PackedForword format

23.
Buffering events tag: bbb, time:201, {name: b_0} Buffer pool time: 200, {name: a_0} time: 102, {name: c_0} time: 112, {name: c_1} retention buffers ﬂushable buffers tag: aaa tag: ccc Fluentd tag: bbb time: 101, {name: b_0} time: 111, {name: b_1} time: 121, {name: b_2} time: 131, {name: b_3} time: 122, {name: c_2} emit event send buffer return buffer (after sending) acquire buffer PackedForword format

24.
Buffering events tag: aaa, time:210, {name: a_1} Buffer pool time: 200, {name: a_0} time: 102, {name: c_0} time: 112, {name: c_1} retention buffers ﬂushable buffers tag: aaa tag: ccc Fluentd time: 122, {name: c_2} time: 201, {name: b_0} tag: bbb emit event

25.
4x faster than  fluent-logger-java fluency/ fluent-logger-java: m3.large fluentd: m3.large See details: https://gist.github.com/komamitsu/c1e4045fe2ddb108cfbf12d5f014b683 But the actual bottleneck of this benchmark might be Fluentd…

26.
Java profiling (1/2) fluencyfluent-logger-java fluency uses off heap for buffer pool Due to synchronization

27.
Java profiling (2/2) fluencyfluent-logger-java GC Pause: 33ms/s GC Pause: 7ms/s

28.
Finding a bottleneck ﬂuency emit(MessagePack serialization & appending to buffer) accounts for most of the duration String.getBytes in MessagePack serialization takes total 18% ObjectMapper.writeValue itself takes 40%

29.
Finding a bottleneck ﬂuency MessagePackGenerator. writeStartArraytakes 10% java.nio.channels.SocketCh annel.write and java.nio.ByteBuffer.allocate Direct are both 0-1%

30.
Finding a bottleneck ﬂuent-logger-java Sendingevents via socket accounts for most of the duration

31.
Future improvements: removing ObjectMapper ObjectMapper canbe removed to improve performance? Hmm. But Fluency accepts Jackson Modules…

32.
Future improvements: reducing useof ObjectMapper ObjectMapper is needed only for serialisation of data not array

33.
Thanks!

Fluency - Yet another fluent logger

More Related Content

What's hot

Similar to Fluency - Yet another fluent logger

Recently uploaded

Fluency - Yet another fluent logger