How exactly logstash-file-input plugin works?


#1

Hi there,

We are facing some delay(5mins to 1hr) between actual log file creation and same log(file) being available in kibana.

We are using file input plugin to read logs and elasticsearch as output plugin. Every hour new log file will be created with name syslog.log followed by hour of the day eg. syslog.log00,syslog.log01..syslog.log23.

Delay is observed during peak hours(from 9Am to 10 PM) and log files with huge number of events(log lines) and this delay keeps going until entire data for that day is processed and indexed.

My question is how exactly "file" input works? New file will not be picked immediately(during peak hours/files with large data) for e.g file syslog.log15 will not be picked even after 15-30mins of its creation or in other words no events of syslog.log15 will be available in kibana even at 15.30.

We are using ELK 5.6.4 with 3 node ES cluster and 2 logstash/data source servers.

Am I missing something? What is the bottleneck in my case? Someone pls guide and help me out.

Thanks in advance,
Shreepad


(Magnus B├Ąck) #2

I assume you have a single file input with a wildcard? Logstash won't pick up new files while it's busy processing old ones. Only after Logstash hits EOF will it go look for new files to potentially pick up, but even then it processes all files in a single thread.


#3

Thanks Magnus for your quick response!

Yes, I have a single file input which is watching multiple directories for log files.
Please find path which is configured in my config file:
path => [ "/var/log/apigee/services/172.//syslog.*"]

Is there any way logstash can process logs bit faster so that delay i mentioned can be reduced? processing is very smooth and near real time when log file is small and generated during non peak hours. I want to process heavy load in near real time.How can I achieve this pls?

Thanks,
Shreepad


#4

Please read path as below:

/var/log/apigee/services/172.*/*/syslog.*


(Guy Boertje) #5

You should switch to using Filebeat which has seen much more recent development.


#6

But my log server(data source) and logstash server are same. Is file plugin not efficient in my case?


(Guy Boertje) #7

No. The rate of generation of new files and the amount of data in each file that you have is better processed with Filebeat. If you can you should separate the two functions onto to two machines - Apigee on one and Logstash on another. Logstash likes to use as much CPU as it can so you may be impacting the Apigee performance by keeping them together.

As a bonus there are other kinds of Beats that you can use to further collect data on your API servers.


#8

Thanks Guyboertje. I will try filebeat as suggested and get back here with my observations.


#9

Hi again

I have installed filebeat in my logstash servers and it is really performing well. New files are immediately picked and we could see logs in kibana as well.

But problem faced now is not all new logs gets processed immediately. We could see only half of the transactions in kibana. e.g say 20L log events are there in log files but only 10L are visible in kibana.

Please let me know how to overcome this? even have tuned filebeat spool size to 4096 and wait delay to 3s.

We also have cron jobs running every hour which will zip and scp logs files to another server. Is this can be reason again for dealy?

Request to get back asap as there are P1 raised against us and we don't find logs in kibana immediately.

Thanks,
Shreepad


(Christian Dahlqvist) #10

Please read this, especially the "Also be patient" part.


#11

Hi Christian,

I understand and agreed :slight_smile:

Please anyone help me with the solution for my issue

Thanks,
Shreepad


(Guy Boertje) #12

We don't know enough of your setup to begin to help.

What we know:

  1. you were putting LS on the same machine as your log file generation apps.
  2. you did put Filebeat in place.

What we don't know:

  1. is LS on its own machine?
  2. how, exactly, are you counting the documents in ES to know that there are some missing?
  3. whether you tried a filebeat input with a file output (no filters, no output conditionals) as the simplest config to verify that the line count in the source log files is the same as the line count in the destination file?
  4. does your config use the drop filter?
  5. does your config have if conditional blocks that restricts which events are sent to ES?

I don't expect you to answer these questions directly, rather to supply as much info as you can. Get creative with ascii-art, draw the system you have, post your beats yaml config, your LS config, your ES queries etc.

There are actually thousands of people doing exactly what you are trying to do without problems - even our Elastic Cloud systems do this with Filebeat, LS and ES.


#13

Hi Guyboertje,

Please find my comment below:

1.is LS on its own machine?

  • No, three services are running on single server and those are data source(logs generating app) ,filebeat and logstash.

2.how, exactly, are you counting the documents in ES to know that there are some missing?

  • Actually there is no miss in data but there is delay. When I count the number of lines in my log file for an hour(say 15th hour of the day) I will find 50,00,000 lines/events but I find only 30,00,000+ events/lines in discover UI(15:00th bar showing 10L+ and 15:30th bar showing 20L+). When I look back discover UI next day for yesterday's data, I will find all 50L events. This is the case for all peak hours. Data is not available in near real time.

3.whether you tried a filebeat input with a file output (no filters, no output conditionals) as the simplest config to verify that the line count in the source log files is the same as the line count in the destination file?

  • I don't feel there is any problem with filebeat as I don't find any data miss, but still I will try this for couple of peak hour log files and get back.

4.does your config use the drop filter?

  • No, we don't use drop in our config.

5.does your config have if conditional blocks that restricts which events are sent to ES?

  • Yes, we have if block in our config. I will share our LS config file here with sensitive information masked.

LS config

input{
                           beats {
                           port => 5044
                           type => "SomeType"
                         }
    }
    filter{
                mutate{
                       gsub => ["message", "\|", ";"]
                }
         grok {
                              patterns_dir => "/logstash-5.6.4/pattern"
                              match => [ "message", "%{PROXY_LOG_PATTERN_1}", "message", "%{PROXY_LOG_PATTERN}", "message", "%{ENTRY_PATTERN}", "message
        ", "%{EXIT_SUCCESS_PATTERN}","message", "%{ENTRY_PATTERN_1}",  "message", "%{ERROR_PATTERN}", "message", "%{ERROR_PATTERN_1}", "message", "%{ENTRY_PATTERN_2}"]
            }
        if [Endpoint] =~ /.+/
         {
        mutate {
         add_field => {
            "NewFieldName" => "%{Endpoint}.%{operation}"
          }
         }
        }
        if [client_sent_end_timestamp] =~ /.+/ and [client_received_end_timestamp] =~ /.+/ and [target_sent_end_timestamp] =~ /.+/ and [target_received_end_timestamp] =
        ~ /.+/ {
        ruby{
        code => **Some calculation**
           add_tag => ["**some tag**"]
            }
           }
        if [client_sent_end_Date_Time] =~ /.+/ and [client_received_end_Date_Time] =~ /.+/ and [target_sent_end_Date_Time] =~ /.+/ and [target_received_end_Date_Time] =~ /.+/ {
        ruby{
        code => **Some calculation**
           add_tag => ["**some tag**"]
            }
           }
         if [**Some field**] =~ /.+/
            {
            ruby
           {
            code => "**Some calculation**"
           }
           }
        date{
            match => [ "Time_Date", "ISO8601" ]
            target => "@timestamp"
            }
        }
        output{
                   if "_grokparsefailure" in [tags]
                   {
                     elasticsearch
                     {
                       hosts => ["ES1:9200","ES2:9200"]
                       index => "grokparsefailure-%{+YYYY.MM.dd}"
                     }
                   }
                   else {
                     elasticsearch
                     {
                       hosts => ["ES1:9200","ES2:9200","ES3:9200"]
                     }
                   }
        }

FB config

#=========================== Filebeat prospectors =============================
#------------------------------ Log prospector --------------------------------
- input_type: log
  paths:
    - /var/log/app/services/*/*/syslog.log*
  ignore_older: 10m
  close_inactive: 5m

#========================= Filebeat global options ============================  
filebeat.spool_size: 4096
filebeat.idle_timeout: 2s

#================================ Outputs ======================================
#----------------------------- Logstash output ---------------------------------
output.logstash:
  # Boolean flag to enable or disable the output module.
  #enabled: true

  # The Logstash hosts
  hosts: ["localhost:5044"]

Rest are set to default.

Please let me know if any further details required.

Thanks,
Shreepad


#14

Hi,

Just to give more clarity on issue faced, please refer below screenshots:

If you just observe the bars in discover tab you will find huge difference in current day's(1) data but If same day's data is checked next day, there won't be any data loss(2).

1

2
image

Thanks,
Shreepad


(system) #15

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.