records in dropped chunks not counted in the metrics when storage.total_limit_size is reached
- Dominant language
- C
- Stars
- 8.1k
- Forks
- 2k
- Avg merge
- 4d 16h
- Merged PRs (30d)
- 58
Description
## Bug Report
### **Describe the bug**
When the chunk folder reaches its maximum size configured in **storage.total_limit_size**, the oldest chunks are deleted, and the records are dropped without being counted as dropped records in the output metric
I use a small value for storage.total_limit_size to repro this issue, but it can be reproducible with 1, 2,3GB, and bigger buffer sizes as long as the chunks fill this buffer the issue will be reproduced.
### Affected platforms K8s and Vanilla
### **To Reproduce**
- Steps to reproduce the problem:
1- create chunk directory
`mdkdir chunks`
2- create logs directory
`mkdir logs`
3- Use flog command
`flog -t log -f json -w -b 1000 -n 200000 -r 10000 -t stdout >> logs/sample.log`
4- Run Fluent-Bit version 2.1.8 using sample [config](#fluentbit-config-file)
`./fluent-bit -c config.conf`
#### Logs
I created a 200000 log sample using https://github.com/calyptia/flog
```
$ wc -l logs/sample.log
200000 logs/sample.log
$ ls -aslh logs/sample.log
53M -rw-rw-r--. 1 user user 53M Aug 31 15:38 logs/sample.log
```
##### Metrics output
After running Fluent-bit, only 149391 records reached the endpoint, and no chunks were left in the storage folder.
```
$ curl localhost:2020/api/v1/metrics|jq
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 391 0 391 0 0 80618 0 --:--:-- --:--:-- --:--:-- 97750
{
"input": {
"tail.0": {
"records": 200000,
"bytes": 62501471,
"files_opened": 1,
"files_closed": 0,
"files_rotated": 0
},
"storage_backlog.1": {
"records": 0,
"bytes": 0
}
},
"filter": {
"modify.0": {
"drop_records": 0,
"add_records": 0,
"records": 200000,
"bytes": 62501471
}
},
"output": {
"http.0": {
"proc_records": 149391,
"proc_bytes": 51319348,
"errors": 0,
"retries": 0,
"retries_failed": 0,
"dropped_records": 0,
"retried_records": 0
}
}
}
```
##### Storage Metrics output
All chunks were deleted from the chunk storage folder
```
$ curl localhost:2020/api/v1/storage|jq
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
100 412 0 412 0 0 85036 0 --:--:-- --:--:-- --:--:-- 100k
{
"storage_layer": {
"chunks": {
"total_chunks": 0,
"mem_chunks": 0,
"fs_chunks": 0,
"fs_chunks_up": 0,
"fs_chunks_down": 0
}
},
"input_chunks": {
"tail.0": {
"status": {
"overlimit": false,
"mem_size": "0b",
"mem_limit": "0b"
},
"chunks": {
"total": 0,
"up": 0,
"down": 0,
"busy": 0,
"busy_size": "0b"
}
},
"storage_backlog.1": {
"status": {
"overlimit": false,
"mem_size": "0b",
"mem_limit": "0b"
},
"chunks": {
"total": 0,
"up": 0,
"down": 0,
"busy": 0,
"busy_size": "0b"
}
}
}
}
```
** Current Behavior**
When the space left in the chunk folder is not enough to accommodate new chunks
```
[2023/08/31 15:47:23] [debug] [input chunk] chunk 4046-1693496843.89811643.flb required 2259056 bytes and 337021 bytes left in plugin http.0
[2023/08/31 15:47:23] [debug] [input chunk] chunk 4046-1693496843.121975750.flb required 2258892 bytes and 337392 bytes left in plugin http.0
[2023/08/31 15:47:23] [debug] [input chunk] chunk 4046-1693496843.154587196.flb required 2259372 bytes and 336909 bytes left in plugin http.0
[2023/08/31 15:47:23] [debug] [input chunk] chunk 4046-1693496843.187080193.flb required 2258604 bytes and 336526 bytes left in plugin http.0
[2023/08/31 15:47:23] [debug] [input chunk] chunk 4046-1693496843.221100210.flb required 2259230 bytes and 336940 bytes left in plugin http.0
[2023/08/31 15:47:23] [debug] [input chunk] chunk 4046-1693496843.253418717.flb required 2258845 bytes and 336761 bytes left in plugin http.0
[2023/08/31 15:47:23] [debug] [input chunk] chunk 4046-1693496843.283686263.flb required 1508135 bytes and 337110 bytes left in plugin http.0
```
The oldest chunks will be dropped
```
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.402050423.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.434178810.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.467253296.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.499251223.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.531052910.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.562882256.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.594415143.flb with no output route from input plugin tail.0
```
The average number of records in the chunks is near 7230
```
egrep records test-log.log|awk '{print $14}'|sort -nr|uniq -c|sort
1 records=4835,
1 records=7213,
1 records=7214,
1 records=7223,
1 records=7225,
1 records=7226,
1 records=7229,
1 records=7231,
1 records=7235,
1 records=7237,
1 records=7238,
2 records=7217,
2 records=7222,
2 records=7233,
2 records=7234,
3 records=7228,
3 records=7230,
3 records=7236,
```
Fluent bit only processed all the 200000 records, but only 149391 were output to the endpoint.
```
"output": {
"http.0": {
"proc_records": 149391,
"proc_bytes": 51319348,
```
and in the logs, we have seven messages indicating that chunks were dropped due to no route from input...
```
ricardo: ~/newIssue-found$ egrep "drop chunk" test-log.log
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.402050423.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.434178810.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.467253296.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.499251223.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.531052910.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.562882256.flb with no output route from input plugin tail.0
[2023/08/31 15:47:23] [debug] [input chunk] drop chunk 4046-1693496842.594415143.flb with no output route from input plugin tail.0
```
Counting drop messages in the logs.
```
ricardo: ~/newIssue-found$ egrep "drop chunk" test-log.log |wc -l
7
```
So, as an estimate, we have **7*7230=50610** records that were not counted as dropped. If we add the processed records and the records dropped when rolling over the chunks, we have the total of the records counted.
Dropped records not counted approximation 50610
+
Processed Output Records. 149391
=~ 200000 Total records in the sample file
**Expected behavior**
The records in the dropped chunks must be counted as dropped in the metrics.
**Your Environment**
* Version used: FB 2.1.8
* Configuration:
#### Fluentbit config File
```
[SERVICE]
grace 0
flush 1
log_level debug
log_file ./test-log.log
http_server on
storage.path chunks
storage.max_chunks_up 1
[INPUT]
refresh_interval 1
name tail
read_from_head on
path logs/*.log
storage.type filesystem
buffer_chunk_size 2M
buffer_max_size 2M
tag
tag_regex (?.*)
[FILTER]
Name modify
Match *
Add Service1 SOMEVALUE
Add Service3 SOMEVALUE3
[OUTPUT]
name http
match *
format json_lines
host 127.0.0.1
port 8443
retry_limit False
tls on
tls.verify off
workers 1
storage.total_limit_size 50M
```
Contributor guide
Assessment
This issue has not been assessed yet.