Fluent-bit: in_forward with filter parser increasingly consumes memory, leak?
Bug Report
Describe the bug
using in_forward with filter parser consumes too much of memory increasingly.
without filter parser, it looks stable.
To Reproduce
- Example log message if applicable:
time:2018-08-01T23:00:49+09:00 remote_addr:10.114.99.27 request_method:GET request_length:58 request_uri:/ https: uri:/ query_string:-status:200 bytes_sent:11428 body_bytes_sent:11250 referer:- useragent:- forwardedfor:- request_time:0.101 upstream_response_time:0
.100, 0.001 upstream_addr:**.***.***.**:*****, **.***.***.**:*****
- Steps to reproduce the problem:
using in_forward with filter parser, its memory consuming increases up to OOM killed. (1Gb)
with out filter section,
--------------------------------------------------------------------------------
Command: bin/fluent-bit -c etc/fluent-bit.conf
Massif arguments: --pages-as-heap=yes --detailed-freq=1000000
ms_print arguments: massif.out.1671
--------------------------------------------------------------------------------
MB
126.8^ #
| :::::::#:::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
| :: ::: #::::::::::::: :::: ::: ::::: ::: :: ::::: :::::::::::::::::::::
0 +----------------------------------------------------------------------->Gi
0 23.34
Number of snapshots: 80
Detailed snapshots: [7 (peak)]
--------------------------------------------------------------------------------
n time(i) total(B) useful-heap(B) extra-heap(B) stacks(B)
--------------------------------------------------------------------------------
0 0 4,554,752 4,554,752 0 0
1 446,248,442 127,922,160 127,922,160 0 0
2 691,520,824 127,902,648 127,902,648 0 0
3 1,024,368,420 129,495,024 129,495,024 0 0
4 1,529,278,628 129,505,320 129,505,320 0 0
5 1,953,815,937 129,490,552 129,490,552 0 0
6 2,320,259,832 127,509,368 127,509,368 0 0
7 2,796,222,119 132,908,664 132,908,664 0 0
...
with filter section
--------------------------------------------------------------------------------
Command: bin/fluent-bit -c etc/fluent-bit.conf
Massif arguments: --pages-as-heap=yes --detailed-freq=1000000
ms_print arguments: massif.out.1703
--------------------------------------------------------------------------------
GB
1.963^ #
| @@#
| @@@@@@@#
| @@@@@@@@@@@#
| @@::@ @@@@@@@@@#
| @@::@ ::@ @@@@@@@@@#
| @@@@ ::@ ::@ @@@@@@@@@#
| @@@@@@@ ::@ ::@ @@@@@@@@@#
| :::@@@ @@@@ ::@ ::@ @@@@@@@@@#
| :::::: @@@ @@@@ ::@ ::@ @@@@@@@@@#
| @@:::::::: @@@ @@@@ ::@ ::@ @@@@@@@@@#
| @::@@: :::::: @@@ @@@@ ::@ ::@ @@@@@@@@@#
| @@::@: @@: :::::: @@@ @@@@ ::@ ::@ @@@@@@@@@#
| :@::@@: @: @@: :::::: @@@ @@@@ ::@ ::@ @@@@@@@@@#
| :@@:@: @@: @: @@: :::::: @@@ @@@@ ::@ ::@ @@@@@@@@@#
| ::@@@:@@:@: @@: @: @@: :::::: @@@ @@@@ ::@ ::@ @@@@@@@@@#
| @@@: @@ :@@:@: @@: @: @@: :::::: @@@ @@@@ ::@ ::@ @@@@@@@@@#
| @:::@@ : @@ :@@:@: @@: @: @@: :::::: @@@ @@@@ ::@ ::@ @@@@@@@@@#
| ::@@@:: @@ : @@ :@@:@: @@: @: @@: :::::: @@@ @@@@ ::@ ::@ @@@@@@@@@#
| ::@: @ @:: @@ : @@ :@@:@: @@: @: @@: :::::: @@@ @@@@ ::@ ::@ @@@@@@@@@#
0 +----------------------------------------------------------------------->Gi
0 13.78
Number of snapshots: 63
Detailed snapshots: [3, 5, 6, 9, 10, 12, 13, 15, 16, 18, 20, 21, 23, 25, 26, 34, 35, 36, 37, 38, 39, 40, 43, 46, 47, 48, 50, 51, 52, 53, 54, 56, 57, 58, 59,
61, 62 (peak)]
--------------------------------------------------------------------------------
n time(i) total(B) useful-heap(B) extra-heap(B) stacks(B)
--------------------------------------------------------------------------------
0 0 4,554,752 4,554,752 0 0
1 330,451,391 157,781,920 157,781,920 0 0
2 510,534,581 177,753,776 177,753,776 0 0
3 721,457,979 202,944,848 202,944,848 0 0
...
--------------------------------------------------------------------------------
n time(i) total(B) useful-heap(B) extra-heap(B) stacks(B)
--------------------------------------------------------------------------------
62 14,799,782,740 2,107,469,488 2,107,469,488 0 0
100.00% (2,107,469,488B) (page allocation syscalls) mmap/mremap/brk, --alloc-fns, etc.
->72.44% (1,526,640,640B) 0x5F1D409: mmap (mmap.c:34)
| ->70.85% (1,493,065,728B) 0x190485: je_pages_map (pages.c:45)
| | ->36.91% (777,961,472B) 0x176353: je_chunk_alloc_mmap (chunk_mmap.c:55)
| | | ->36.91% (777,961,472B) 0x17570F: je_chunk_alloc_wrapper (chunk.c:357)
| | | | ->36.91% (777,961,472B) 0x163D14: arena_chunk_alloc (arena.c:599)
| | | | ->33.03% (696,176,640B) 0x166BC6: arena_bin_malloc_hard (arena.c:1220)
| | | | | ->33.03% (696,176,640B) 0x169DDD: je_arena_malloc_hard (arena.c:2606)
| | | | | ->17.91% (377,458,688B) 0x159A1F: realloc (arena.h:1357)
| | | | | | ->14.73% (310,353,920B) 0x22469B: msgpack_sbuffer_write (sbuffer.h:77)
| | | | | | | ->12.34% (260,034,560B) 0x22447D: msgpack_pack_array (pack_template.h:713)
| | | | | | | | ->12.34% (260,034,560B) 0x22528B: cb_parser_filter (filter_parser.c:281)
| | | | | | | | ->12.34% (260,034,560B) 0x1AFB2E: flb_filter_do (flb_filter.c:86)
| | | | | | | | ->12.34% (260,034,560B) 0x1AD1BC: flb_input_dbuf_write_end (flb_input.h:642)
| | | | | | | | ->12.34% (260,034,560B) 0x1AEC82: flb_input_dyntag_append_obj (flb_input.c:866)
| | | | | | | | ->12.34% (260,034,560B) 0x1F41C7: fw_prot_process (fw_prot.c:225)
| | | | | | | | ->12.34% (260,034,560B) 0x1F3210: fw_conn_event (fw_conn.c:73)
| | | | | | | | ->12.34% (260,034,560B) 0x1B7272: flb_engine_start (flb_engine.c:542)
| | | | | | | | ->12.34% (260,034,560B) 0x153A30: main (fluent-bit.c:824)
...
Expected behavior
in_forward with filter should not consume too much of memory
Your Environment
- Configuration:
fluent-bit.conf
[SERVICE]
Flush 1
Daemon Off
Log_Level error
Parsers_File /fluent-bit/etc/parsers.conf
HTTP_Server On
HTTP_Listen 0.0.0.0
HTTP_PORT 2020
[INPUT]
Name Forward
Listen 127.0.0.1
Port 24224
Buffer_Max_Size 128M
Mem_Buf_Limit 128M
Chunk_Size 64M
[FILTER]
Name parser
Match proxy
Key_Name log
Parser proxy
[OUTPUT]
Name stdout
parsers.conf
[PARSER]
Name proxy
Format regex
Regex ^time:(?<time>[^\s]*)\s*remote_addr:(?<remote_addr>[^\s]*)\s*request_method:(?<request_method>[^\s]*)\s*request_length:(?<request_length>[^\s]*)\s*request_uri:(?<request_uri>[^\s]*)\s*https:(?<https>[^\s]*)\s*uri:(?<uri>[^\s]*)\s*query_string:(?<query_string>[^\s]*)\s*status:(?<status>[^\s]*)\s*bytes_sent:(?<bytes_sent>[^\s]*)\s*body_bytes_sent:(?<body_bytes_sent>[^\s]*)\s*referer:(?<referer>[^\s]*)\s*useragent:(?<useragent>[^\s].*)\s*forwardedfor:(?<forwardedfor>[^\s]*)\s*request_time:(?<request_time>[^\s]*)\s*upstream_response_time:(?<upstream_response_time>[^\s]*)\s*upstream_addr:(?<upstream_addr>[^\s]*)
Time_Key time
Time_Format %Y-%m-%dT%H:%M:%S%z
- Environment name and version (e.g. Kubernetes? What version?):
- fluent-bit : commit df6d858dd69a5926a36411e244e756f0e5eee7f8 (tag: v0.13.6, origin/0.13)
- docker: 17.09.1-ce
- sytem: x86_64 GNU/Linux 4.14.11
log generator
docker run -d \
--log-driver=fluentd \
--log-opt fluentd-address=localhost:24224 \
--log-opt tag=proxy \
--log-opt max-size=1m \
--log-opt max-file=1 \
--log-opt mode=non-blocking \
--log-opt max-buffer-size=1k \
--name proxy \
-p :8080 \
nginx
Dockerfile for fluent-bit
FROM gcr.io/google-containers/debian-base-amd64:0.3 as builder
# Fluent Bit version
ENV FLB_MAJOR 0
ENV FLB_MINOR 13
ENV FLB_PATCH 6
ENV FLB_VERSION 0.13.6
ENV DEBIAN_FRONTEND noninteractive
RUN mkdir -p /fluent-bit/bin /fluent-bit/etc /fluent-bit/log /tmp/src/
COPY . /tmp/src/
RUN rm -rf /tmp/src/build/*
RUN apt-get update && apt-get dist-upgrade -y && apt-get install -y build-essential cmake make wget unzip libsystemd-dev libssl1.0-dev libasl-dev valgrind
WORKDIR /tmp/src/build/
RUN cmake -DFLB_DEBUG=On \
-DFLB_TRACE=On \
-DFLB_MTRACE=On \
-DFLB_VALGRIND=On \
-DFLB_STATS=On \
-DFLB_METRICS=On \
-DFLB_JEMALLOC=On \
-DFLB_BUFFERING=On \
-DFLB_TLS=On \
-DFLB_WITHOUT_SHARED_LIB=On \
-DFLB_WITHOUT_EXAMPLES=On \
-DFLB_HTTP_SERVER=On \
-DFLB_OUT_KAFKA=On ..
RUN make
RUN install bin/fluent-bit /fluent-bit/bin/
# Configuration files
COPY conf/fluent-bit.conf \
conf/parsers.conf \
conf/parsers_java.conf \
conf/parsers_extra.conf \
conf/parsers_openstack.conf \
conf/parsers_cinder.conf \
/fluent-bit/etc/
FROM gcr.io/google-containers/debian-base-amd64:0.3
MAINTAINER Eduardo Silva <[email protected]>
LABEL Description="Fluent Bit docker image" Vendor="Fluent Organization" Version="1.1"
RUN apt-get update \
&& apt-get dist-upgrade -y \
&& apt-get install --no-install-recommends ca-certificates libssl1.0.2 -y build-essential procps valgrind \
&& rm -rf /var/lib/apt/lists/* \
&& apt-get autoclean
COPY --from=builder /fluent-bit /fluent-bit
#
EXPOSE 2020
# Entry point
CMD ["/fluent-bit/bin/fluent-bit", "-c", "/fluent-bit/etc/fluent-bit.conf"]
keyolk
All 5 comments
for test,
- send 100~5000 qps of requests to generate 5000 line of access log
- wait 1 minutes
- stop sending requests
but it doesn't release memory
keyolk
on 2 Aug 2018
Thank you for reporting. I sent a patch #702
nokute78
on 2 Aug 2018
👍1
@nokute78 Thanks!
I just found that, leak is occured when the given parser meet non formated log like error log.
I'll try your patch on my env : )
keyolk
on 2 Aug 2018
seems it fixes my issue : )
keyolk
on 2 Aug 2018
🎉1
702 has been merged.
the fix will be merged also in 0.13 branch for 0.13.7 release.
thanks again @keyolk and @nokute78 !
edsiper
on 6 Aug 2018
👍1
Was this page helpful?
0 / 5 - 0 ratings
Related issues
edsiper
路
4Comments
JavaCS3
路
3Comments
jcdauchy-moodys
路
3Comments
mhf-ir
路
4Comments
arienchen
路
3Comments