Should vector be maintaining open file handles to `ignore_older` files older than the cutoff?

[jszwedko]

I'm not sure if this is a bug or expected behavior, but it looks like, when using the ignore_older config for the file source, Vector still maintains an open file handle to the files with a modified time before the cutoff.

From gitter: https://gitter.im/timberio-vector/community?at=5f456c28c3aa024ef99e4907 . The user was trying to limit the number of open file handles, by using the ignore_older config.

If it is expected, we should probably call it out in the docs as I was not expecting that. It seemingly limits its usefulness in avoiding resource consumption.

Vector Version

vector 0.11.0 (g8b4ff32 x86_64-unknown-linux-gnu 2020-08-25)

Vector Configuration File

data_dir = "/tmp/vector"

[sources.in]
  type = "file" # required
  ignore_older = 10  # optional, no default, seconds
  include = ["/tmp/log/*.log"] # required

[sinks.http]
  type = "console"
  inputs = ["in"]
  encoding.codec = "json"

Debug Output

Aug 25 16:57:23.252  INFO vector: Log level "debug" is enabled.
Aug 25 16:57:23.256  INFO vector: Loading configs. path=["/tmp/test.toml"]
Aug 25 16:57:23.276  INFO vector::topology: Running healthchecks.
Aug 25 16:57:23.276  INFO vector::topology: Starting source "in"
Aug 25 16:57:23.277  INFO vector::topology::builder: Healthcheck: Passed.
Aug 25 16:57:23.277  INFO vector::topology: Starting sink "http"
Aug 25 16:57:23.277  INFO vector: Vector has started. version="0.11.0" git_version="v0.9.0-573-g8b4ff32" released="Tue, 25 Aug 2020 20:48:03 +0000" arch="x86_64"
Aug 25 16:57:23.277  INFO source{name=in type=file}: vector::sources::file: Starting file server. include=["/tmp/log/*.log"] exclude=[]
Aug 25 16:57:23.279  INFO source{name=in type=file}:file_server: vector::internal_events::file: found new file to watch. path="/tmp/log/a.log"
Aug 25 16:57:23.280 DEBUG source{name=in type=file}:file_server: vector::internal_events::file: files checkpointed. count=0
Aug 25 16:57:24.315 DEBUG source{name=in type=file}:file_server: vector::internal_events::file: files checkpointed. count=0
Aug 25 16:57:25.340 DEBUG source{name=in type=file}:file_server: vector::internal_events::file: files checkpointed. count=0
Aug 25 16:57:27.391 DEBUG source{name=in type=file}:file_server: vector::internal_events::file: files checkpointed. count=0
^CAug 25 16:57:28.368  INFO vector: Vector has stopped.
Aug 25 16:57:28.370  INFO vector::topology: Shutting down... Waiting on: in, http. 59 seconds left
Aug 25 16:57:28.370 DEBUG source{name=in type=file}: vector::topology::builder: Finished
Aug 25 16:57:28.370 DEBUG sink{name=http type=console}: vector::topology::builder: Finished

Expected Behavior

Vector does not open the file

Actual Behavior

Vector opens the file

Additional Context

$ lsof -p 27049 | grep a.log
vector  27049 CORP\jesse   15r      REG              259,3    104581 178538005 /tmp/log/a.log

[ktff]

So description for ignore_older option is somewhat misleading/incomplete. Currently it is:

Ignore files with a data modification date that does not exceed this age.

which doesn't say that it will collect newer data from the file. That's why it's tailing them, as it only ignores the old data not the file. So a clearer description would be:

Ignore existing data in files with a data modification date older than this age. Subsequent data will be collected.

This is the expected behavior, so just the documentation should be updated.

[binarylogic]

Hm, that's not how I thought the option to works. I think the behavior should change. The idea is to ignore older files as if they don't exist, not just older data. This ensures that Vector does not open file handles for the file, etc.

[binarylogic]

@ktff, we're working on an RFC to improve the file source in #3480. I think we should address this there.

[lukesteensen]

The idea is to ignore older files as if they don't exist, not just older data.

What would you want to happen with a file that initially has not been modified since ignore_older but then starts getting writes? If you want to start reading only the new data, we'd need to keep track of where that starts somehow. Right now we do it with the file cursor.

[binarylogic]

That's a good point. Ideally, we'd rediscover the file and read the new data only, but in the interim we would not hold a file handle for it.

[jszwedko]

That's a good point. Ideally, we'd rediscover the file and read the new data only, but in the interim we would not hold a file handle for it.

I think I like that, but it does seem like it would make it trickier to figure out which file contents were new. I guess you could keep track of the sizes of the ignored files and then seek to that point when their mtime changes? That wouldn't handle the case that the file is overwritten, rather than appended to, though.

[lukesteensen]

I guess you could keep track of the sizes of the ignored files and then seek to that point when their mtime changes? That wouldn't handle the case that the file is overwritten, rather than appended to, though.

Yeah, you'd at least need to make sure the fingerprint was the same or weird things could happen.

Another confusing case would be if Vector is started, ignores a file for an old mtime, then Vector is stopped, then the file is written to, then Vector is started again. At that point, it would (depending on the config) read the whole file from the beginning, including data it had been ignoring to that point. Right now I think we avoid that via the normal checkpointing of open files.

[ktff]

I think the behavior should change

In that case whatever solution we come up with to avoid holding file handles it should be useable for other files as well. So we can reduce total file handle usage further. This way we can avoid some of the special casing and use the normal checkpointing to avoid the issues @lukesteensen mentioned.

[vbichov]

Is there a workaround to that issue?

In my use-case, there are many short-lived jobs that generate roughly 100000 files per month. Now due to business requirements, we can't delete the files before that.
I'm looking for a way to limit the number of tailed files somehow (I.E by looking at ctime). Any way to do that?

[ktff]

@vbichov

Is there a workaround to that issue?

One way is to point Vector to a folder with symlinks to the files and then have two services/scripts that will create symlinks and delete older ones.