Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Add new log file reader for filestream input #21450

Merged

Conversation

kvch
Copy link
Contributor

@kvch kvch commented Oct 1, 2020

What does this PR do?

This PR adds the new refactored version of the previous Log reader of the log input called logFile. The differences between the two readers are the following:

  • logFile calls Stat only once to avoid too many system calls (Log calls Stat 3 times after every read)
  • logFile starts separate go routines to check if close.after_interval or close.inactive has elapsed. Log checks close_inactive after every Read. Thus, if the output is blocked, it cannot stop the reader.
  • logFile does not check if the file has been removed or renamed if close_removed or close_renamed are enabled. Instead it is checked separately in the prospector, so if the output blocks, the reader can be closed. This prevents Filebeat keeping too many open files if the output is blocked. (The code mentioned is not yet included in any PR.)

Why is it important?

This is the improved version of the previous log reader.

Checklist

  • My code follows the style guidelines of this project
  • I have commented my code, particularly in hard-to-understand areas
    - [ ] I have made corresponding changes to the documentation
    - [ ] I have made corresponding change to the default configuration files
    - [ ] I have added tests that prove my fix is effective or that my feature works
    - [ ] I have added an entry in CHANGELOG.next.asciidoc or CHANGELOG-developer.next.asciidoc.

Related issues

Rebased on #21444

@kvch kvch requested a review from faec October 1, 2020 13:40
@botelastic botelastic bot added the needs_team Indicates that the issue/PR needs a Team:* label label Oct 1, 2020
@kvch kvch added the Team:Services (Deprecated) Label for the former Integrations-Services team label Oct 1, 2020
@elasticmachine
Copy link
Collaborator

Pinging @elastic/integrations-services (Team:Services)

@botelastic botelastic bot removed the needs_team Indicates that the issue/PR needs a Team:* label label Oct 1, 2020
Copy link
Contributor

@faec faec left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

just a minor comment / question (aside from the comments on #21444 since I assume that will be merged first), approved


func (f *logFile) closeIfInactive(ctx unison.Canceler) {
// TODO it can be optimized
for ctx.Err() == nil {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This looks like a spin lock, should there be a sleep or timer channel here? (Is that what the "optimized" comment is referring to?)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, I just rewrote the loop. Now it checks the state every five minutes. It seems like a good compromise between checking constantly between making the user configure it.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Let me know what you think about it.

@kvch kvch force-pushed the feature-filebeat-log-reader-for-filestream branch from c43d3bd to 9d36d23 Compare October 2, 2020 08:58
@kvch kvch added the needs_backport PR is waiting to be backported to other branches. label Oct 2, 2020
@elasticmachine
Copy link
Collaborator

elasticmachine commented Oct 2, 2020

💔 Tests Failed

Pipeline View Test View Changes Artifacts preview

Expand to view the summary

Build stats

  • Build Cause: [Pull request #21450 updated]

  • Start Time: 2020-10-02T10:39:02.218+0000

  • Duration: 36 min 51 sec

Test stats 🧪

Test Results
Failed 4
Passed 1769
Skipped 131
Total 1904

Test errors

Expand to view the tests failures

  • Name: Build&Test / filebeat-build / TestFileWatchNewDeleteModified – filestream

    • Age: 1
    • Duration: 0
    • Error Details: Failed
  • Name: Build&Test / filebeat-build / TestFileWatchNewDeleteModified/two_modified_files – filestream

    • Age: 1
    • Duration: 0
    • Error Details: Failed
  • Name: Build&Test / x-pack/filebeat-build / TestConfigOauth2Validation – httpjson

    • Age: 1
    • Duration: 0.03
    • Error Details: Failed
  • Name: Build&Test / x-pack/filebeat-build / TestConfigOauth2Validation/date_cursor.date_format_will_fail_if_invalid – httpjson

    • Age: 1
    • Duration: 0
    • Error Details: Failed

Steps errors

Expand to view the steps failures

  • Name: mage build test

    • Description: mage build test

    • Duration: 2 min 56 sec

    • Start Time: 2020-10-02T11:05:36.193+0000

    • log

  • Name: Extract

    • Description: tar -xpf source.tgz

    • Duration: 0 min 28 sec

    • Start Time: 2020-10-02T11:05:45.975+0000

    • log

  • Name: Error signal

    • Description: untar: step failed with error script returned exit code 1

    • Duration: 0 min 0 sec

    • Start Time: 2020-10-02T11:06:14.319+0000

    • log

  • Name: mage build test

    • Description: mage build test

    • Duration: 8 min 14 sec

    • Start Time: 2020-10-02T11:05:35.924+0000

    • log

  • Name: Extract

    • Description: tar -xpf source.tgz

    • Duration: 1 min 39 sec

    • Start Time: 2020-10-02T11:05:51.628+0000

    • log

  • Name: Error signal

    • Description: untar: step failed with error script returned exit code 1

    • Duration: 0 min 0 sec

    • Start Time: 2020-10-02T11:06:30.714+0000

    • log

Log output

Expand to view the last 100 lines of log output

[2020-10-02T11:13:50.464Z] c1e54eec4b57: Pulling fs layer
[2020-10-02T11:13:50.730Z] c1e54eec4b57: Verifying Checksum
[2020-10-02T11:13:50.730Z] c1e54eec4b57: Download complete
[2020-10-02T11:13:51.001Z] c1e54eec4b57: Pull complete
[2020-10-02T11:13:51.001Z] Digest: sha256:b733d4a32c4da6a00a84df2ca32791bb03df95400243648d8c539e7b4cce329c
[2020-10-02T11:13:51.001Z] Status: Downloaded newer image for alpine:3.4
[2020-10-02T11:13:53.287Z] + python .ci/scripts/pre_archive_test.py
[2020-10-02T11:13:53.287Z] Copy ./x-pack/filebeat/build into build/x-pack/filebeat/build
[2020-10-02T11:13:53.309Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-21450/src/github.com/elastic/beats/build
[2020-10-02T11:13:53.320Z] WARNING: Unknown parameter(s) found for class type 'hudson.tasks.junit.pipeline.JUnitResultsStep': id,stashedTestReports
[2020-10-02T11:13:53.328Z] Recording test results
[2020-10-02T11:13:54.708Z] Stashed 3 file(s)
[2020-10-02T11:13:54.718Z] Archiving artifacts
[2020-10-02T11:13:55.282Z] + python .ci/scripts/search_system_tests.py
[2020-10-02T11:13:55.298Z] [INFO] system-tests='build/x-pack/filebeat/build/system-tests'. If no empty then let's create a tarball
[2020-10-02T11:13:55.612Z] + tar --version
[2020-10-02T11:13:55.921Z] + tar --exclude=x-pack-filebeat--system-tests-linux.tgz -czf x-pack-filebeat--system-tests-linux.tgz build/x-pack/filebeat/build/system-tests
[2020-10-02T11:13:55.938Z] Archiving artifacts
[2020-10-02T11:13:56.368Z] Client: Docker Engine - Community
[2020-10-02T11:13:56.368Z]  Version:           19.03.13
[2020-10-02T11:13:56.368Z]  API version:       1.40
[2020-10-02T11:13:56.368Z]  Go version:        go1.13.15
[2020-10-02T11:13:56.368Z]  Git commit:        4484c46d9d
[2020-10-02T11:13:56.368Z]  Built:             Wed Sep 16 17:02:36 2020
[2020-10-02T11:13:56.368Z]  OS/Arch:           linux/amd64
[2020-10-02T11:13:56.368Z]  Experimental:      false
[2020-10-02T11:13:56.368Z] 
[2020-10-02T11:13:56.368Z] Server: Docker Engine - Community
[2020-10-02T11:13:56.368Z]  Engine:
[2020-10-02T11:13:56.368Z]   Version:          19.03.13
[2020-10-02T11:13:56.368Z]   API version:      1.40 (minimum version 1.12)
[2020-10-02T11:13:56.368Z]   Go version:       go1.13.15
[2020-10-02T11:13:56.368Z]   Git commit:       4484c46d9d
[2020-10-02T11:13:56.368Z]   Built:            Wed Sep 16 17:01:06 2020
[2020-10-02T11:13:56.368Z]   OS/Arch:          linux/amd64
[2020-10-02T11:13:56.368Z]   Experimental:     false
[2020-10-02T11:13:56.368Z]  containerd:
[2020-10-02T11:13:56.368Z]   Version:          1.3.7
[2020-10-02T11:13:56.368Z]   GitCommit:        8fba4e9a7d01810a393d5d25a3621dc101981175
[2020-10-02T11:13:56.368Z]  runc:
[2020-10-02T11:13:56.368Z]   Version:          1.0.0-rc10
[2020-10-02T11:13:56.368Z]   GitCommit:        dc9208a3303feef5b3839f4323d9beb36df0a9dd
[2020-10-02T11:13:56.368Z]  docker-init:
[2020-10-02T11:13:56.368Z]   Version:          0.18.0
[2020-10-02T11:13:56.368Z]   GitCommit:        fec3683
[2020-10-02T11:14:01.000Z] Failed in branch x-pack/filebeat-build
[2020-10-02T11:14:06.260Z] [INFO] unstashV2: JOB_GCS_BUCKET is set. bucket param got precedency instead.
[2020-10-02T11:14:06.269Z] [INFO] unstashV2: JOB_GCS_CREDENTIALS is set. credentialsId param got precedency instead.
[2020-10-02T11:14:06.344Z] [Google Cloud Storage Plugin] Found 1 files to download from pattern: gs://beats-ci-temp/Beats/beats/PR-21450-3/source/source.tgz
[2020-10-02T11:14:06.370Z] [Google Cloud Storage Plugin] Downloading: Beats/beats/PR-21450-3/source/source.tgz to local path: /var/lib/jenkins/workspace/Beats_beats_PR-21450/source.tgz
[2020-10-02T11:14:17.785Z] + tar --version
[2020-10-02T11:14:18.086Z] + tar -xpf source.tgz
[2020-10-02T11:14:30.641Z] + rm source.tgz
[2020-10-02T11:14:30.699Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-21450/src/github.com/elastic/beats
[2020-10-02T11:14:30.708Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-21450/src/github.com/elastic/beats/uncategorized-1601636512113
[2020-10-02T11:14:30.760Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-21450/src/github.com/elastic/beats/filebeat-build-1601636856159
[2020-10-02T11:14:30.798Z] Running in /var/lib/jenkins/workspace/Beats_beats_PR-21450/src/github.com/elastic/beats/x-pack-filebeat-build-1601637234371
[2020-10-02T11:14:31.141Z] + cat
[2020-10-02T11:14:31.141Z] + /usr/local/bin/runbld ./runbld-test-reports --job-name elastic+beats+pull-request
[2020-10-02T11:14:31.141Z] Picked up JAVA_TOOL_OPTIONS: -Dfile.encoding=UTF8
[2020-10-02T11:14:37.846Z] runbld>>> runbld started
[2020-10-02T11:14:37.846Z] runbld>>> 1.6.12/f45d832f2ba0aa2722ab4ec1fda8ad140f027f8b
[2020-10-02T11:14:39.764Z] runbld>>> The following profiles matched the job 'elastic+beats+pull-request' in order of occurrence in the config (last value wins).
[2020-10-02T11:14:40.025Z] runbld>>> Matches in the system config:
[2020-10-02T11:14:40.025Z] runbld>>> - Matched ^elastic\+beats
[2020-10-02T11:14:40.025Z] runbld>>> - Matched ^elastic\+beats\+pull-request
[2020-10-02T11:14:41.415Z] runbld>>> Debug logging enabled.
[2020-10-02T11:14:41.415Z] runbld>>> Storing result
[2020-10-02T11:14:41.415Z] runbld>>> Store result: created {:total 2, :successful 2, :failed 0} 1
[2020-10-02T11:14:41.415Z] runbld>>> BUILD: https://c150076387b5421f9154dfbf536e5c60.us-west1.gcp.cloud.es.io:9243/build-1597739501209/t/20201002111441-82C3FE21
[2020-10-02T11:14:41.415Z] runbld>>> Adding system facts.
[2020-10-02T11:14:42.808Z] runbld>>> Adding vcs info for the latest commit:  850916cda6b098193e48b9da4fde9ec83cf040ef
[2020-10-02T11:14:42.808Z] runbld>>> >>>>>>>>>>>> SCRIPT EXECUTION BEGIN >>>>>>>>>>>>
[2020-10-02T11:14:42.808Z] runbld>>> Adding /usr/lib/jvm/java-8-openjdk-amd64/bin to the path.
[2020-10-02T11:14:42.808Z] + echo 'Processing JUnit reports with runbld...'
[2020-10-02T11:14:42.808Z] Processing JUnit reports with runbld...
[2020-10-02T11:14:43.070Z] runbld>>> <<<<<<<<<<<< SCRIPT EXECUTION END <<<<<<<<<<<<
[2020-10-02T11:14:43.070Z] runbld>>> DURATION: 29ms
[2020-10-02T11:14:43.070Z] runbld>>> STDOUT: 40 bytes
[2020-10-02T11:14:43.070Z] runbld>>> STDERR: 49 bytes
[2020-10-02T11:14:43.070Z] runbld>>> WRAPPED PROCESS: SUCCESS (0)
[2020-10-02T11:14:43.070Z] runbld>>> Searching for build metadata in /var/lib/jenkins/workspace/Beats_beats_PR-21450
[2020-10-02T11:14:44.021Z] runbld>>> Storing build metadata: 
[2020-10-02T11:14:44.021Z] runbld>>> Adding test report.
[2020-10-02T11:14:44.021Z] runbld>>> Searching for junit test output files with the pattern: TEST-.*\.xml$ in: /var/lib/jenkins/workspace/Beats_beats_PR-21450/src/github.com/elastic/beats
[2020-10-02T11:14:44.971Z] runbld>>> Found 4 test output files
[2020-10-02T11:14:45.542Z] runbld>>> Test output logs contained: Errors: 0 Failures: 4 Tests: 1904 Skipped: 122
[2020-10-02T11:14:45.542Z] runbld>>> Storing result
[2020-10-02T11:14:45.542Z] runbld>>> FAILURES: 4
[2020-10-02T11:14:46.486Z] runbld>>> Store result: updated {:total 2, :successful 2, :failed 0} 2
[2020-10-02T11:14:46.486Z] runbld>>> BUILD: https://c150076387b5421f9154dfbf536e5c60.us-west1.gcp.cloud.es.io:9243/build-1597739501209/t/20201002111441-82C3FE21
[2020-10-02T11:14:46.748Z] runbld>>> Email notification disabled by environment variable.
[2020-10-02T11:14:46.748Z] runbld>>> Slack notification disabled by environment variable.
[2020-10-02T11:14:52.495Z] Running on Jenkins in /var/lib/jenkins/workspace/Beats_beats_PR-21450
[2020-10-02T11:14:52.707Z] [INFO] getVaultSecret: Getting secrets
[2020-10-02T11:14:52.802Z] Masking supported pattern matches of $VAULT_ADDR or $VAULT_ROLE_ID or $VAULT_SECRET_ID
[2020-10-02T11:14:53.505Z] + chmod 755 generate-build-data.sh
[2020-10-02T11:14:53.505Z] + ./generate-build-data.sh https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats/PR-21450/ https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats/PR-21450/runs/3 FAILURE 2151027
[2020-10-02T11:14:53.505Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats/PR-21450/runs/3/steps/?limit=10000 -o steps-info.json
[2020-10-02T11:14:55.366Z] INFO: curl https://beats-ci.elastic.co/blue/rest/organizations/jenkins/pipelines/Beats/beats/PR-21450/runs/3/tests/?status=FAILED -o tests-errors.json

@kvch kvch force-pushed the feature-filebeat-log-reader-for-filestream branch from 9d36d23 to 850916c Compare October 2, 2020 10:38
@kvch kvch merged commit 1945373 into elastic:master Oct 2, 2020
@kvch kvch added v7.10.0 and removed needs_backport PR is waiting to be backported to other branches. labels Oct 2, 2020
v1v added a commit to v1v/beats that referenced this pull request Oct 2, 2020
…ne-2.0-arm

* upstream/master: (54 commits)
  [CI] Change x-pack/auditbeat build events (comments, labels) (elastic#21463)
  [CI] changeset from elastic#20603 was not added to CI2.0 (elastic#21464)
  Add new log file reader for filestream input (elastic#21450)
  [CI] Send slack message with build status (elastic#21428)
  Remove duplicated sources url in dependencies report (elastic#21462)
  Add implementation of FSWatcher and FSScanner for filestream (elastic#21444)
  [Ingest Manager] Split index restrictions into type,dataset, namespace parts (elastic#21406)
  Update Filebeat module expected logs files (elastic#21454)
  Edit SQL module docs and fix broken doc structure (elastic#21233)
  [Ingest Manager] Send snapshot flag together with metadata (elastic#21285)
  Revert "[JJBB] Set shallow cloning to 10 (elastic#21409)" (elastic#21447)
  [JJBB] Use reference repo for fast checkouts (elastic#21410)
  Add initial skeleton of filestream input (elastic#21427)
  Initial spec file for apm-server (elastic#21225)
  [Ingest Manager] Upgrade Action: make source URI optional (elastic#21372)
  Add field limit check for AWS Cloudtrail flattened fields (elastic#21388)
  [Winlogbeat] Move winlogbeat javascript processor to libbeat (elastic#21402)
  ci: pipeline to generate the changelog (elastic#21426)
  [JJBB] Set shallow cloning to 10 (elastic#21409)
  docs: add link to release notes for 7.9.2 (elastic#21405) (elastic#21419)
  ...
v1v added a commit to v1v/beats that referenced this pull request Oct 2, 2020
…ci-build-label-support

* upstream/master:
  [CI] Change x-pack/auditbeat build events (comments, labels) (elastic#21463)
  [CI] changeset from elastic#20603 was not added to CI2.0 (elastic#21464)
  Add new log file reader for filestream input (elastic#21450)
  [CI] Send slack message with build status (elastic#21428)
  Remove duplicated sources url in dependencies report (elastic#21462)
  Add implementation of FSWatcher and FSScanner for filestream (elastic#21444)
  [Ingest Manager] Split index restrictions into type,dataset, namespace parts (elastic#21406)
  Update Filebeat module expected logs files (elastic#21454)
  Edit SQL module docs and fix broken doc structure (elastic#21233)
  [Ingest Manager] Send snapshot flag together with metadata (elastic#21285)
  Revert "[JJBB] Set shallow cloning to 10 (elastic#21409)" (elastic#21447)
  [JJBB] Use reference repo for fast checkouts (elastic#21410)
  Add initial skeleton of filestream input (elastic#21427)
  Initial spec file for apm-server (elastic#21225)
  [Ingest Manager] Upgrade Action: make source URI optional (elastic#21372)
  Add field limit check for AWS Cloudtrail flattened fields (elastic#21388)
  [Winlogbeat] Move winlogbeat javascript processor to libbeat (elastic#21402)
  ci: pipeline to generate the changelog (elastic#21426)
v1v added a commit to v1v/beats that referenced this pull request Oct 5, 2020
…-matches-found

* upstream/master: (21 commits)
  Skip filestream flaky tests (elastic#21490)
  Ignore unsupported metrics in the azure module (elastic#21486)
  Do not run symlink tests on Windows (elastic#21472)
  Map `cloud.account.id` to azure sub id (elastic#21483)
  Add support for app_state metricset (elastic#20639)
  Include original error when metricbeat fails to connect with Kafka (elastic#21484)
  Prompt only when agent is already enrolled (elastic#21473)
  Fix leftover delpoyment example (elastic#21474)
  Bump version to ECS 1.6 in modules without ECS updates (elastic#21455)
  Clarify input type configuration options (elastic#19284)
  Increase index pattern size check to 10MiB (elastic#21487)
  Migrate S3 Input to Filebeat Input V2 (elastic#20005)
  [libbeat] Add configurable exponential backoff for disk queue write errors (elastic#21493)
  Revert "Revert "[JJBB] Set shallow cloning to 10 (elastic#21409)" (elastic#21447)" (elastic#21467)
  Fix format of debug messages in tlscommon (elastic#21482)
  [CI] Change x-pack/auditbeat build events (comments, labels) (elastic#21463)
  [CI] changeset from elastic#20603 was not added to CI2.0 (elastic#21464)
  Add new log file reader for filestream input (elastic#21450)
  [CI] Send slack message with build status (elastic#21428)
  Remove duplicated sources url in dependencies report (elastic#21462)
  ...
kvch added a commit to kvch/beats that referenced this pull request Oct 5, 2020
## What does this PR do?

This PR adds the new refactored version of the previous `Log` reader of the `log` input called `logFile`. The differences between the two readers are the following:

* `logFile` calls `Stat` only once to avoid too many system calls (`Log` calls `Stat` 3 times after every read)
* `logFile` starts separate go routines to check if `close.after_interval` or `close.inactive` has elapsed. `Log` checks `close_inactive` after every `Read`. Thus, if the output is blocked, it cannot stop the reader.
* `logFile` does not check if the file has been removed or renamed if `close_removed` or `close_renamed` are enabled. Instead it is checked separately in the prospector, so if the output blocks, the reader can be closed. This prevents Filebeat keeping too many open files if the output is blocked. (The code mentioned is not yet included in any PR.)

## Why is it important?

This is the improved version of the previous `log` reader.

(cherry picked from commit 1945373)
kvch added a commit that referenced this pull request Oct 5, 2020
## What does this PR do?

This PR adds the new refactored version of the previous `Log` reader of the `log` input called `logFile`. The differences between the two readers are the following:

* `logFile` calls `Stat` only once to avoid too many system calls (`Log` calls `Stat` 3 times after every read)
* `logFile` starts separate go routines to check if `close.after_interval` or `close.inactive` has elapsed. `Log` checks `close_inactive` after every `Read`. Thus, if the output is blocked, it cannot stop the reader.
* `logFile` does not check if the file has been removed or renamed if `close_removed` or `close_renamed` are enabled. Instead it is checked separately in the prospector, so if the output blocks, the reader can be closed. This prevents Filebeat keeping too many open files if the output is blocked. (The code mentioned is not yet included in any PR.)

## Why is it important?

This is the improved version of the previous `log` reader.

(cherry picked from commit 1945373)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Team:Services (Deprecated) Label for the former Integrations-Services team v7.10.0
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants