promtail: failed to get file size from tailer

[karlism]

Describe the bug
Warning in logs about "failed to get file size from tailer", even after file permissions are fixed.

To Reproduce
Steps to reproduce the behavior:

1. Started promtail with file that is not readable by it:

$ ls -la /var/log/secure 
-rw-------. 1 root promtail 52620 Nov 27 10:09 /var/log/secure

$ id
uid=995(promtail) gid=993(promtail) groups=993(promtail) context=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023

$ cat /tmp/promtail.yml 
---
server:
  http_listen_port: 9080
  grpc_listen_port: 0

positions:
  filename: "/tmp/positions.yaml"

clients:
  - url: http://localhost:3100/loki/api/v1/push

scrape_configs:
  - job_name: "syslog"
    static_configs:
    - labels:
        __path__: /var/log/secure
        hostname: example 
      targets:
      - localhost

$ promtail -config.file=/tmp/promtail.yml
level=warn ts=2019-11-27T10:09:44.001016071Z caller=filetargetmanager.go:98 msg="WARNING!!! entry_parser config is deprecated, please change to pipeline_stages"
level=info ts=2019-11-27T10:09:44.002788218Z caller=server.go:121 http=[::]:9080 grpc=[::]:40217 msg="server listening on addresses"
level=info ts=2019-11-27T10:09:44.003031419Z caller=main.go:65 msg="Starting Promtail" version="(version=, branch=, revision=)"
level=info ts=2019-11-27T10:09:49.002257219Z caller=filetargetmanager.go:257 msg="Adding target" key="{hostname=\"example\"}"
level=info ts=2019-11-27T10:09:49.002767046Z caller=tailer.go:77 component=tailer msg="start tailing file" path=/var/log/secure
level=warn ts=2019-11-27T10:09:59.00261028Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:10:09.002732629Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:10:19.002609644Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:10:29.0026004Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:10:39.002652665Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:10:49.00261526Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:10:59.002594739Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:11:09.002617555Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:11:19.002663034Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:11:29.002638308Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:11:39.002608083Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"

2. Fix /var/log/secure permissions to make it readable by promtail group (keep promtail process started in the previous step running):

# ls -la /var/log/secure                                                            
-rw-------. 1 root promtail 53181 Nov 27 10:11 /var/log/secure
# chmod 640 /var/log/secure 
# ls -la /var/log/secure 
-rw-r-----. 1 root promtail 53181 Nov 27 10:11 /var/log/secure

3. check promtail output and see that warning is still triggered despite the fact that file permissions have been fixed:

level=warn ts=2019-11-27T10:11:49.002671707Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:11:59.002703483Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"
level=warn ts=2019-11-27T10:12:09.002599977Z caller=filetarget.go:328 msg="failed to get file size from tailer, " file=/var/log/secure error="invalid argument"

4. stop promtail process and start it again, no more failed to get file size from tailer warnings:

level=info ts=2019-11-27T10:12:15.859932457Z caller=signals.go:54 msg="=== received SIGINT/SIGTERM ===\n*** exiting"
level=info ts=2019-11-27T10:12:15.860284257Z caller=filetargetmanager.go:318 msg="Removing target" key="{hostname=\"example\"}"
level=info ts=2019-11-27T10:12:15.860488258Z caller=tailer.go:148 component=tailer msg="stopped tailing file" path=/var/log/secure
level=error ts=2019-11-27T10:12:15.860516184Z caller=logerror.go:11 message="stopping tailer" error="Unable to open file /var/log/secure: open /var/log/secure: permission denied"

$ promtail -config.file=/tmp/promtail.yml
level=warn ts=2019-11-27T10:12:23.055725794Z caller=filetargetmanager.go:98 msg="WARNING!!! entry_parser config is deprecated, please change to pipeline_stages"
level=info ts=2019-11-27T10:12:23.057605768Z caller=server.go:121 http=[::]:9080 grpc=[::]:44792 msg="server listening on addresses"
level=info ts=2019-11-27T10:12:23.057871365Z caller=main.go:65 msg="Starting Promtail" version="(version=, branch=, revision=)"
level=info ts=2019-11-27T10:12:28.056328163Z caller=filetargetmanager.go:257 msg="Adding target" key="{hostname=\"example\"}"
ts=2019-11-27T10:12:28.056923762Z caller=log.go:124 component=tailer level=info msg="Seeked /var/log/secure - &{Offset:0 Whence:0}"
level=info ts=2019-11-27T10:12:28.056997482Z caller=tailer.go:77 component=tailer msg="start tailing file" path=/var/log/secure

Expected behavior
I would expect errors to go away after action in step 2 are performed without restarting promtail service, especially since the warning is triggered repeatedly, which makes me assume that it tries to repeatedly open the log file, but cannot succeed.

Environment:

• Infrastructure: CentOS 7.7 x86_64 VM, Promtail 1.0.0

[slim-bean]

Is there a use case where this is really important to fix? Restarting promtail doesn't seem terrible to me if you are updating permissions on files/directories.

[karlism]

I'm deploying promtail by ansible and making sure logfile permissions are correct or fixed during deployment, but I would assume that this issue might manifest in other scenarios, for example, when log rotation is involved.

[stale]

This issue has been automatically marked as stale because it has not had any activity in the past 30 days. It will be closed in 7 days if no further activity occurs. Thank you for your contributions.

[mkfischer]

We are also encountering this problem as logs are rotated. Our environment uses Nomad for container orchestration, with some nodes running 15 or more services; so logs are rotated frequently.

[slim-bean]

I'm sorry @karlism that I didn't look more closely at this when you opened the issue to see that it was such an easy fix :(

[MalloZup]

@slim-bean I do think we should improve the error msg promting that there is no permission on file. invalid argument is imho to generic and seem more a promtail cli/conf error

[saikrishna1488]

We are also encountering this problem as logs are rotated. Our environment uses Nomad for container orchestration, with some nodes running 15 or more services; so logs are rotated frequently.

I have promtail installed i my amazonlinux 2 ec2 instance to view the nginx aceess logs and for nginx access logs have log rotated enabled. Can i assume due to this i am getting this error?