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

[Auditbeat] Determine event.action based on diff against state #22170

Merged

Conversation

andrewkroh
Copy link
Member

What does this PR do?

Rather than using an event.action that is derived from the OS flags provided in the
file notification event the FIM module will determine the event.action based on the
diff between the stored state for the path and the new state.

Why is it important?

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.

@botelastic botelastic bot added needs_team Indicates that the issue/PR needs a Team:* label and removed needs_team Indicates that the issue/PR needs a Team:* label labels Oct 27, 2020
@elasticmachine
Copy link
Collaborator

elasticmachine commented Oct 27, 2020

💚 Build Succeeded

the below badges are clickable and redirect to their specific view in the CI or DOCS
Pipeline View Test View Changes Artifacts preview

Expand to view the summary

Build stats

  • Build Cause: Pull request #22170 updated

    • Start Time: 2021-02-01T14:30:18.496+0000
  • Duration: 30 min 5 sec

  • Commit: 0542651

Test stats 🧪

Test Results
Failed 0
Passed 978
Skipped 222
Total 1200

💚 Flaky test report

Tests succeeded.

Expand to view the summary

Test stats 🧪

Test Results
Failed 0
Passed 978
Skipped 222
Total 1200

@andrewkroh
Copy link
Member Author

The initial attempt with

	if event.Action != InitialScan {
		event.Action = action
	}

doesn't work because you lose actions for renames and deletes (they just appear as attribute_modified.

So perhaps we should only use the diff'ed action for updates.

@andrewkroh andrewkroh force-pushed the bugfix/ab/use-computed-diff-as-action branch from f783ba4 to ee60d0d Compare October 27, 2020 02:06
@andrewkroh
Copy link
Member Author

Relates: #17347

if err != nil {
return sid, owner, errors.Wrapf(err, "failed to convert path:'%s' to UTF16", path)
}
if err = GetNamedSecurityInfo(pathW, FileObject,
Copy link
Contributor

Choose a reason for hiding this comment

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

The problem here was:

  • Some applications will open files for writing in exclusive mode (non FILE_READ_SHARED).
  • ReadOpen above wants read access, so it fails with permission denied.

As GetSecurityInfo doesn't need read access to the file, but only the metadata (READ_CONTROL), I tried opening the file with just that flag. This also fails because the underlying CreateFile will internally add more permissions to the request (SYNCHRONIZE|FILE_READ_ATTRIBUTES) which causes it to still fail for files open with exclusivity.

Finally I came across this SO thread: https://stackoverflow.com/questions/58393139/createfilew-for-read-control-fails-with-access-is-denied-despite-being-owner-o that points to using GetNamedSecurityInfo, which internally does an NtOpenFile call with the minimum required permissions.

@adriansr
Copy link
Contributor

jenkins, test this

1 similar comment
@adriansr
Copy link
Contributor

adriansr commented Dec 1, 2020

jenkins, test this

@andrewkroh andrewkroh marked this pull request as ready for review December 21, 2020 16:22
@andrewkroh andrewkroh requested a review from a team as a code owner December 21, 2020 16:22
@elasticmachine
Copy link
Collaborator

Pinging @elastic/security-external-integrations (Team:Security-External Integrations)

@andrewkroh
Copy link
Member Author

With the current changes I am seeing attributes_modified when only mtime changed. 👍 @adriansr

One thing I noticed is that I get a sequence of created->deleted->created for new files. Is that explained by some OS behavior? I saw it with both a text editor saving a file and a firefox download on Windows.

Screen Shot 2020-12-22 at 9 30 07 PM

auditbeat-fim-create-delete-create.json.txt

@adriansr adriansr self-assigned this Dec 28, 2020
@adriansr
Copy link
Contributor

adriansr commented Dec 29, 2020

@andrewkroh I've tested under Windows server 2016 and didn't get the created->deleted->created sequence.

This is saving a file with notepad:
Screen Shot 2020-12-29 at 15 35 10

Also got similar result with notepad++, but lost the screen capture.

Download a file with iexplore:

Screen Shot 2020-12-29 at 15 41 32

Download a file with Firefox:
Screen Shot 2020-12-29 at 16 34 38

Screen Shot 2020-12-29 at 16 35 08

My understanding is that Windows server 2016 and Windows 10 should behave similarly? Maybe differences in the underlying filesystem?

@andrewkroh
Copy link
Member Author

Your test results look good. I was testing on GCP. The machine is still running if you wanted to look at it.

@adriansr
Copy link
Contributor

Seems like a different behavior under Windows server 2019:

Screen Shot 2020-12-30 at 11 51 47

This sequence is indeed what we're getting from fsnotify:

2020-12-30T10:48:45.254Z INFO instance/beat.go:454 auditbeat start running.
2020-12-30T10:48:45.254Z INFO [monitoring] log/log.go:118 Starting metrics logging every 30s
2020-12-30T10:48:51.583Z INFO [file_integrity] file_integrity/eventreader_fsnotify.go:97 Started fsnotify watcher {"file_path": ["C:\Users\adrian_serrano\Documents"], "recursive": true}
2020-12-30T10:49:05.625Z DEBUG [file_integrity] file_integrity/eventreader_fsnotify.go:138 Received fsnotify event {"file_path": "C:\Users\adrian_serrano\Documents\doc.txt", "event_flags": "CREATE"}
2020-12-30T10:49:05.628Z DEBUG [file_integrity] file_integrity/eventreader_fsnotify.go:138 Received fsnotify event {"file_path": "C:\Users\adrian_serrano\Documents\doc.txt", "event_flags": "REMOVE"}
2020-12-30T10:49:05.631Z DEBUG [file_integrity] file_integrity/metricset.go:281 File changed since it was last seen {"file_path": "C:\Users\adrian_serrano\Documents\doc.txt", "took": 0, "event": {"action": "created", "old": null, "new": {"timestamp":"2020-12-30T10:49:05.6280538Z","path":"C:\Users\adrian_serrano\Documents\doc.txt","info":null,"source":"fsnotify","action":"created"}}}
2020-12-30T10:49:05.734Z DEBUG [file_integrity] file_integrity/eventreader_fsnotify.go:138 Received fsnotify event {"file_path": "C:\Users\adrian_serrano\Documents\doc.txt", "event_flags": "CREATE"}
2020-12-30T10:49:05.740Z DEBUG [file_integrity] file_integrity/eventreader_fsnotify.go:138 Received fsnotify event {"file_path": "C:\Users\adrian_serrano\Documents\doc.txt", "event_flags": "WRITE"}
2020-12-30T10:49:05.740Z DEBUG [file_integrity] file_integrity/metricset.go:281 File changed since it was last seen {"file_path": "C:\Users\adrian_serrano\Documents\doc.txt", "took": 0, "event": {"action": "deleted", "old": null, "new": {"timestamp":"2020-12-30T10:49:05.6319632Z","path":"C:\Users\adrian_serrano\Documents\doc.txt","info":null,"source":"fsnotify","action":"deleted"}}}
2020-12-30T10:49:05.745Z DEBUG [file_integrity] file_integrity/metricset.go:281 File changed since it was last seen {"file_path": "C:\Users\adrian_serrano\Documents\doc.txt", "took": 3906500, "event": {"action": "created", "old": null, "new": {"timestamp":"2020-12-30T10:49:05.7354821Z","path":"C:\Users\adrian_serrano\Documents\doc.txt","info":{"inode":3096224743861787,"uid":0,"gid":0,"sid":"S-1-5-21-3277996792-4287217755-2489893845-1001","owner":"AKROH-WINDOWS\adrian_serrano","group":"","size":12,"mtime":"2020-12-30T10:49:05.7101082Z","ctime":"2020-12-30T10:49:05.6251136Z","type":"file","mode":438,"setuid":false,"setgid":false,"origin":null},"source":"fsnotify","action":"created","hash":{"sha1":"2ef7bde608ce5404e97d5f042f95f89f1c232871"}}}}

Looking at it via Process Monitor shows that when saving a file for the first time (Save...), it is first created and deleted, then created and written to:

Screen Shot 2020-12-30 at 12 13 15

When saved using the Save option (no file-selection dialog) it results in just an update event:

Screen Shot 2020-12-30 at 12 15 58

Screen Shot 2020-12-30 at 12 16 35

I believe the first create-delete sequence is the file-selection dialog verifying that the target file can be created before the dialog is closed.


For the Firefox issue however, I couldn't reproduce the created->deleted->created, but I got something that I believe is wrong:

Screen Shot 2020-12-30 at 12 38 33

It's missing a final event for the target file (moved/created/updated?). I'm looking into it.

@adriansr
Copy link
Contributor

jenkins test this please

andrewkroh and others added 9 commits January 13, 2021 21:33
Rather than using an event.action that is derived from the OS flags provided in the
file notification event the FIM module will determine the event.action based on the
diff between the stored state for the path and the new state.
Update the file-state tracking to support the case where we receive a
DELETE event but we observe the file as already re-created (event.Info
is not nil and hashes are likely populated).

Before this change, we would report a deletion but at the same store the
hashes and file info. Then, a following CREATION event would be ignored
because the diff-ing loggic doesn't take the previous action into
account (in this case prev.action==Deleted).

The best is to ignore the deletion and report on the observed file
changes (if any). Otherwise we have to deal with complex logic in the
cases where the OS event includes multiple actions ( ...|DELETED|...).
@adriansr adriansr force-pushed the bugfix/ab/use-computed-diff-as-action branch from b0effb9 to b30f19a Compare January 13, 2021 20:35
@andrewkroh
Copy link
Member Author

I tested out the a build of this on Windows 2019 (same one in GCP). The results LGTM🥇

Thank you @adriansr!

Saving a file with no changes:
Screen Shot 2021-02-01 at 8 47 41 AM

Downloading a file with FF:

Screen Shot 2021-02-01 at 8 46 17 AM

@andrewkroh andrewkroh added the needs_backport PR is waiting to be backported to other branches. label Feb 1, 2021
@adriansr
Copy link
Contributor

adriansr commented Feb 1, 2021

Will add a changelog entry

@adriansr adriansr merged commit 4a44fac into elastic:master Feb 1, 2021
adriansr pushed a commit to adriansr/beats that referenced this pull request Feb 1, 2021
…ic#22170)

Rather than using an event.action that is derived from the OS flags provided in the
file notification event the FIM module will determine the event.action based on the
diff between the stored state for the path and the new state.

----

Update the file-state tracking to support the case where we receive a
DELETE event but we observe the file as already re-created (event.Info
is not nil and hashes are likely populated).

Before this change, we would report a deletion but at the same store the
hashes and file info. Then, a following CREATION event would be ignored
because the diff-ing logic doesn't take the previous action into
account (in this case prev.action==Deleted).

The best is to ignore the deletion and report on the observed file
changes (if any). Otherwise we have to deal with complex logic in the
cases where the OS event includes multiple actions ( ...|DELETED|...).

Co-authored-by: Adrian Serrano <adrisr83@gmail.com>
(cherry picked from commit 4a44fac)
@adriansr adriansr added v7.12.0 and removed needs_backport PR is waiting to be backported to other branches. labels Feb 1, 2021
adriansr added a commit that referenced this pull request Feb 1, 2021
… (#23788)

Rather than using an event.action that is derived from the OS flags provided in the
file notification event the FIM module will determine the event.action based on the
diff between the stored state for the path and the new state.

----

Update the file-state tracking to support the case where we receive a
DELETE event but we observe the file as already re-created (event.Info
is not nil and hashes are likely populated).

Before this change, we would report a deletion but at the same store the
hashes and file info. Then, a following CREATION event would be ignored
because the diff-ing logic doesn't take the previous action into
account (in this case prev.action==Deleted).

The best is to ignore the deletion and report on the observed file
changes (if any). Otherwise we have to deal with complex logic in the
cases where the OS event includes multiple actions ( ...|DELETED|...).

Co-authored-by: Adrian Serrano <adrisr83@gmail.com>
(cherry picked from commit 4a44fac)

Co-authored-by: Andrew Kroh <andrew.kroh@elastic.co>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants