# Process downloaded log files

**URL:** <https://discuss.elastic.co/t/process-downloaded-log-files/180948>\
**Category:** Logstash\
**Created:** [May 14, 2019, 8:12am UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948 "2019-05-14T08:12:13Z")\
**Posts on this page:** 12\
**Page:** 1

<div class="post-metadata">

**Author:** ![Yogendra\_Hada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yogendra_hada/32/42335_2.png) [@Yogendra\_Hada](https://discuss.elastic.co/u/Yogendra_Hada)\
**Post date:** [May 14, 2019, 8:12am UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/1 "2019-05-14T08:12:13Z")

</div>

Hi,

I am downloading files from S3 on a daily basis. The number of files are quite huge. approximately~ 2,50,000.  
I want Logstash to process these files and send events to Elasticsearch before I encounter next download of files. i.e. next day.

I have some confusion related to the file input plugin.

1. Should I use the "read" or "tail" mode?
2. What is the significance of "start\_position" =\> "beginning"? I used it and it serves the purpose. Just need to check if I am doing the right thing.
3. How do I verify if Logstash has read and processed all the files in a particular day?

My LogStash.conf input looks something like this:-

> input {  
> file {  
> path =\> "/local/kdmlogs/\*/\*/\*"  
> max\_open\_files =\> 99999  
> exclude =\> "\*.s3logs"  
> mode =\> "read"  
> start\_position =\> "beginning"  
> ignore\_older =\> 86400  
> close\_older =\> 86400  
> sincedb\_path =\> "/usr/yogehada/var/.sincedb"  
> sincedb\_clean\_after =\> 2.5  
> tags =\> ["logs"]  
> }  
> }

---

<div class="post-metadata">

**Author:** ![Badger](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/badger/32/25190_2.png) [@Badger](https://discuss.elastic.co/u/Badger)\
**Post date:** [May 14, 2019, 2:21pm UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/2 "2019-05-14T14:21:12Z")

</div>

1. tail mode is useful for tailing log files to which a process is actively writing data. If you have files that have been written out and you just want to read the entire file then use read mode.

2. In tail mode, when log stash first sees a file, by default it seeks to the end and just listens for new data, it ignores any data already in the file. start\_position =\> beginning tells it to read the file from the beginning. This only applies the first time logstash sees the file. In read mode it is ignored (as is close\_older).

3. In read mode, when logstash has finished reading the file, by default, it deletes it. Once all the files are deleted, they have all been read. Alternatively, if you tell it to log the file names it has read you could check that list for completeness.

---

<div class="post-metadata">

**Author:** ![Yogendra\_Hada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yogendra_hada/32/42335_2.png) [@Yogendra\_Hada](https://discuss.elastic.co/u/Yogendra_Hada)\
**Post date:** [May 14, 2019, 7:43pm UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/3 "2019-05-14T19:43:30Z")

</div>

Thanks for the reply mate @Badger .  
So now I am convinced that I should be using the "read" mode.

I killed logstash process and tried to start it again. But now it doesn't read any files.  
I tried removing the ignore\_older and still no help.  
In the debug logs this is what I see:-

> [2019-05-14T19:38:25,763][DEBUG][logstash.agent] Converging pipelines state {:actions\_count=\>0}  
> [2019-05-14T19:38:26,218][DEBUG][logstash.outputs.file] Starting stale files cleanup cycle {:files=\>{}}  
> [2019-05-14T19:38:26,218][DEBUG][logstash.outputs.file] 0 stale files found {:inactive\_files=\>{}}  
> [2019-05-14T19:38:26,646][DEBUG][logstash.outputs.file] Starting flush cycle  
> [2019-05-14T19:38:27,370][DEBUG][logstash.instrument.periodicpoller.cgroup] One or more required cgroup files or directories not found: /proc/self/cgroup, /sys/fs/cgroup/cpuacct, /sys/fs/cgroup/cpu  
> [2019-05-14T19:38:27,635][DEBUG][org.logstash.execution.PeriodicFlush] Pushing flush onto pipeline.  
> [2019-05-14T19:38:28,134][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=\>"ParNew"}  
> [2019-05-14T19:38:28,134][DEBUG][logstash.instrument.periodicpoller.jvm] collector name {:name=\>"ConcurrentMarkSweep"}  
> [2019-05-14T19:38:28,646][DEBUG][logstash.outputs.file] Starting flush cycle  
> [2019-05-14T19:38:28,762][DEBUG][logstash.config.source.local.configpathloader] Skipping the following files while reading config since they don't match the specified glob pattern {:files=\>["/usr/share/logstash/CONTRIBUTORS", "/usr/share/logstash/Gemfile", "/usr/share/logstash/Gemfile.lock", "/usr/share/logstash/LICENSE.txt", "/usr/share/logstash/NOTICE.TXT", "/usr/share/logstash/bin", "/usr/share/logstash/config", "/usr/share/logstash/data", "/usr/share/logstash/lib", "/usr/share/logstash/logs", "/usr/share/logstash/logstash-core", "/usr/share/logstash/logstash-core-plugin-api", "/usr/share/logstash/modules", "/usr/share/logstash/tools", "/usr/share/logstash/vendor", "/usr/share/logstash/x-pack"]}  
> [2019-05-14T19:38:28,762][DEBUG][logstash.config.source.local.configpathloader] Reading config file {:config\_file=\>"/usr/share/logstash/LogStash.conf"}  
> [2019-05-14T19:38:28,764][DEBUG][logstash.agent] Converging pipelines state {:actions\_count=\>0}  
> [2019-05-14T19:38:30,647][DEBUG][logstash.outputs.file] Starting flush cycle  
> [2019-05-14T19:38:31,762][DEBUG][logstash.config.source.local.configpathloader] Skipping the following files while reading config since they don't match the specified glob pattern {:files=\>["/usr/share/logstash/CONTRIBUTORS", "/usr/share/logstash/Gemfile", "/usr/share/logstash/Gemfile.lock", "/usr/share/logstash/LICENSE.txt", "/usr/share/logstash/NOTICE.TXT", "/usr/share/logstash/bin", "/usr/share/logstash/config", "/usr/share/logstash/data", "/usr/share/logstash/lib", "/usr/share/logstash/logs", "/usr/share/logstash/logstash-core", "/usr/share/logstash/logstash-core-plugin-api", "/usr/share/logstash/modules", "/usr/share/logstash/tools", "/usr/share/logstash/vendor", "/usr/share/logstash/x-pack"]}  
> [2019-05-14T19:38:31,762][DEBUG][logstash.config.source.local.configpathloader] Reading config file {:config\_file=\>"/usr/share/logstash/LogStash.conf"}  
> [2019-05-14T19:38:31,764][DEBUG][logstash.agent] Converging pipelines state {:actions\_count=\>0}

No events are being processed and also I don't see any errors in the logs. It looks like some kind of infinite loops. Tried restarting logstash but no help.

---

<div class="post-metadata">

**Author:** ![Yogendra\_Hada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yogendra_hada/32/42335_2.png) [@Yogendra\_Hada](https://discuss.elastic.co/u/Yogendra_Hada)\
**Post date:** [May 14, 2019, 7:57pm UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/4 "2019-05-14T19:57:00Z")

</div>

Also, I deleted the old .sincedb file before starting Logstash.  
This is how my Logstash.conf looks.

> input {  
> file {  
> path =\> "/local/kdmlogs/\*/\*/\*"  
> max\_open\_files =\> 50000  
> exclude =\> "\*.s3logs"  
> mode =\> "read"  
> file\_completed\_action =\> "log"  
> file\_completed\_log\_path =\> "/local/metric/files\_processed"  
> start\_position =\> "beginning"  
> #ignore\_older =\> 86400  
> sincedb\_path =\> "/usr/yogehada/var/.sincedb"  
> sincedb\_clean\_after =\> 2.5  
> tags =\> ["logs"]  
> }  
> }  
> filter {  
> if "logs" in [tags] {  
> grok {  
> id =\> "parse\_log\_line"  
> match =\> {  
> "message" =\> "%{YEAR:year}%{MONTHNUM:month}%{MONTHDAY:date}:%{HOUR}%{MINUTE}(%{SECOND}) %{SYSLOGPROG}:%{GREEDYDATA:syslog\_message}"  
> }  
> }  
> grok {  
> id =\> "parse\_filename"  
> match =\> {  
> "path" =\> "/local/kdmlogs/\*/\*/%{GREEDYDATA}#%{GREEDYDATA:device\_type}#%{GREEDYDATA:software\_version}#%{GREEDYDATA:dsn}#%{GREEDYDATA:s3key}"  
> }  
> }  
> #Remove fields we don 't want (to save space)  
> mutate {  
> remove\_field =\> ["message", "path", "host"]  
> }  
> }  
> metrics {  
> meter =\> "events"  
> add\_tag =\> "metric"  
> }  
> }  
> output {  
> if "_grokparsefailure" not in [tags] and "logs" in [tags] {  
> amazon\_es {  
> hosts =\> ["${HOST}"]  
> region =\> "us-east-1"  
> aws\_access\_key\_id =\> "${ACCESSKEY}"  
> aws\_secret\_access\_key =\> "${SECRET}"  
> index =\> "sys\_logs_%{+YYYY.MM.dd}"  
> }  
> }  
> if "metric" in [tags] {  
> file {  
> path =\> "/local/metric/test-metric.txt"  
> codec =\> line {  
> format =\> "rate: %{[events][rate\_1m]}"  
> }  
> }  
> }  
> }

---

<div class="post-metadata">

**Author:** ![Badger](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/badger/32/25190_2.png) [@Badger](https://discuss.elastic.co/u/Badger)\
**Post date:** [May 14, 2019, 8:44pm UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/5 "2019-05-14T20:44:11Z")

</div>

If you have files that match the pattern "/local/kdmlogs/\*/\*/\*" but that do not have filenames that match "\*.s3logs" then you should see them being read and added to "/local/metric/files\_processed".

Is it possible you meant "/local/kdmlogs/\*\*/\*" (i.e. a recursive descent)?

If you still do not get anything enable log.level trace (through either the command line, logstash.yml, or specifically for filewatch as described in [this](https://discuss.elastic.co/t/logstash-6-5-0-stops-shipping-logs-to-es/175477/5) post).

---

<div class="post-metadata">

**Author:** ![Yogendra\_Hada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yogendra_hada/32/42335_2.png) [@Yogendra\_Hada](https://discuss.elastic.co/u/Yogendra_Hada)\
**Post date:** [May 14, 2019, 8:51pm UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/6 "2019-05-14T20:51:45Z")

</div>

Hi @Badger ,

My actual log files are present under "/local/kdmlogs/\*/\*/" .  
There are two levels of subdirectories under /local/kdmlogs. It was working perfectly fine before this. Let me enable the trace loglevel

---

<div class="post-metadata">

**Author:** ![Yogendra\_Hada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yogendra_hada/32/42335_2.png) [@Yogendra\_Hada](https://discuss.elastic.co/u/Yogendra_Hada)\
**Post date:** [May 14, 2019, 9:48pm UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/7 "2019-05-14T21:48:52Z")

</div>

After enabling, trace level logging this is what I see in the logs:-

> [2019-05-14T21:02:46,634][TRACE][filewatch.discoverer] discover\_files handling: {"new discovery"=\>true, "watched\_file details"=\>"\<FileWatch::WatchedFile: @filename='9223351846341672359#726#Kindle 5.11.1 (3527990035)#9804d1903e4064994ed60372c2ef4e21#4a25d%2F1557657288%2F9804d1903e4064994ed60372c2ef4e21.1557657269993:DET:UPLOAD', @state='watched', @recent\_states='[:watched]', @bytes\_read='0', @bytes\_unread='0', current\_size='333254', last\_stat\_size='333254', file\_open?='false', @initial=true, @sincedb\_key='24775306 0 64768'\>"}  
> [2019-05-14T21:02:46,634][TRACE][filewatch.sincedbcollection] associate: finding {"inode"=\>"24775306", "path"=\>"/local/kdmlogs/2019051319/91/9223351846341672359#726#Kindle 5.11.1 (3527990035)#9804d1903e4064994ed60372c2ef4e21#4a25d%2F1557657288%2F9804d1903e4064994ed60372c2ef4e21.1557657269993:DET:UPLOAD"}  
> [2019-05-14T21:02:46,634][TRACE][filewatch.sincedbcollection] associate: unmatched  
> [2019-05-14T21:02:46,635][TRACE][filewatch.discoverer] discover\_files handling: {"new discovery"=\>true, "watched\_file details"=\>"\<FileWatch::WatchedFile: @filename='9223351846341684579#726#Kindle 5.11.1 (3527990035)#add089b1d9d0d50c67a262050c74cba0#18f20%2F1557652348%2Fadd089b1d9d0d50c67a262050c74cba0.1557652324692:DET:UPLOAD', @state='watched', @recent\_states='[:watched]', @bytes\_read='0', @bytes\_unread='0', current\_size='710', last\_stat\_size='710', file\_open?='false', @initial=true, @sincedb\_key='24775349 0 64768'\>"}  
> [2019-05-14T21:02:46,635][TRACE][filewatch.sincedbcollection] associate: finding {"inode"=\>"24775349", "path"=\>"/local/kdmlogs/2019051319/91/9223351846341684579#726#Kindle 5.11.1 (3527990035)#add089b1d9d0d50c67a262050c74cba0#18f20%2F1557652348%2Fadd089b1d9d0d50c67a262050c74cba0.1557652324692:DET:UPLOAD"}  
> [2019-05-14T21:02:46,635][TRACE][filewatch.sincedbcollection] associate: unmatched  
> [2019-05-14T21:02:46,636][TRACE][filewatch.discoverer] discover\_files handling: {"new discovery"=\>true, "watched\_file details"=\>"\<FileWatch::WatchedFile: @filename='9223351846341704272#726#Kindle 5.11.1 (3527990035)#853ea75b6a45313932cb2a43c59f209e#49e2f%2F1557645334%2F853ea75b6a45313932cb2a43c59f209e.1557645308668:DET:UPLOAD', @state='watched', @recent\_states='[:watched]', @bytes\_read='0', @bytes\_unread='0', current\_size='227427', last\_stat\_size='227427', file\_open?='false', @initial=true, @sincedb\_key='24776898 0 64768'\>"}

I am not sure what this actually means.  
I presume it discovers the file and looks it in the sincedb collection, doesn't find it and calls it unmatched.

---

<div class="post-metadata">

**Author:** ![Yogendra\_Hada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yogendra_hada/32/42335_2.png) [@Yogendra\_Hada](https://discuss.elastic.co/u/Yogendra_Hada)\
**Post date:** [May 15, 2019, 6:09am UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/8 "2019-05-15T06:09:19Z")

</div>

Hi @Badger, did you find time to look at the log above?

Thanks.

---

<div class="post-metadata">

**Author:** ![Badger](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/badger/32/25190_2.png) [@Badger](https://discuss.elastic.co/u/Badger)\
**Post date:** [May 15, 2019, 2:27pm UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/9 "2019-05-15T14:27:05Z")

</div>

I did but I do not understand the filewatch code well enough to interpret it. It is finding the files and knows they are not zero length, but does not appear to start reading them. I do not understand how that could happen.

---

<div class="post-metadata">

**Author:** ![Yogendra\_Hada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/yogendra_hada/32/42335_2.png) [@Yogendra\_Hada](https://discuss.elastic.co/u/Yogendra_Hada)\
**Post date:** [May 15, 2019, 5:29pm UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/10 "2019-05-15T17:29:28Z")

</div>

An update on this. After around 15 hours, logstash started reading some files.  
However the event rate that I captured from the "metrics" plugin was too low ~2000 events/sec. I usually get an average of 25,0000 events/sec.

It stopped again after an hour. It didn't read all the files from the subdirectory.

---

<div class="post-metadata">

**Author:** ![guyboertje](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/guyboertje/32/31592_2.png) [@guyboertje](https://discuss.elastic.co/u/guyboertje)\
**Post date:** [May 23, 2019, 6:09pm UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/11 "2019-05-23T18:09:49Z")

</div>

Unfortunately there is not enough components at TRACE level logging.

I need as many `filewatch.readmode.*` components as possible logging at TRACE.

What is the output of `curl -XGET 'localhost:9600/_node/logging?pretty'`?

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [June 20, 2019, 6:09pm UTC](https://discuss.elastic.co/t/process-downloaded-log-files/180948/12 "2019-06-20T18:09:51Z")

</div>

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