promtail goes nuts when logfile is a symbolic link

[sni]

Describe the bug
Using promtail with a static_configs hangs when hitting symbolic links.

To Reproduce

1. Started Promtail (tested with 0.4.0) to tail /var/log/* when there are symbolic links in that folder like test.log -> other.log.

It ends up with tousands of messages like this per second:

ts=2019-11-08T09:04:27.778140536Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778213701Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."

/opt/omd/sites/test/var/log/naemon.log is a symbolic link to ../naemon/naemon.log in this case and does exist and is readable.

Finally promtail has to be killed with -9.

Expected behavior
I would expect promtail to follow the symbolic link and use that file.

Environment:

• Infrastructure: centos 8 virtual machine

Screenshots, Promtail config, or terminal output

ts=2019-11-08T09:04:27.777608435Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.777670541Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.777739361Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.777794702Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.777860715Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.777931427Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778002251Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778055279Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778140536Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778213701Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778281933Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778349275Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778423162Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778491736Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778559357Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778627166Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778699319Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."
ts=2019-11-08T09:04:27.778769075Z caller=log.go:124 component=tailer level=info msg="Waiting for /opt/omd/sites/test/var/log/naemon.log to appear..."

[slim-bean]

Is the file pointed to by the link readable by the user running the Promtail process?

Will have to look at why this is logging so aggressively, that shouldn't be happening

[sni]

yes, like i wrote, the file is readably and exists. A "normal" tail from the terminal works as expected.

[slim-bean]

Can you share the output of ls -al for both the symlink and the file?

[sni]

$ ls -la /opt/omd/sites/test/var/log/naemon.log $(realpath /opt/omd/sites/test/var/log/naemon.log)
lrwxrwxrwx. 1 test test   20 Nov  8 09:15 /opt/omd/sites/test/var/log/naemon.log -> ../naemon/naemon.log
-rw-r--r--. 1 test test 3234 Nov  8 10:20 /opt/omd/sites/test/var/naemon/naemon.log

everything runs as user test.

[slim-bean]

My initial thought here is it may be the relative path used in the symlink, can you make the link with an absolute path and see if that works?

[sni]

yes, that works. Using an absolute path in the symlink works.

[slim-bean]

Ok, I am away from my computer but will take a look to see why the relative path doesn't work and if it's possible to support that

[sni]

great, thanks

[slim-bean]

As well as we definitely should not be logging at that frequency

[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.

[mwmahlberg]

Changing the symlinks does not solve the issue. Sometimes, for examlple with TKGI (formerly PKS) you do not have the possibility to change the symlinks.

This issue currently prevents my company from evaluating Loki.

[michaelkebe]

I think promtail should be fixed and allow symlink with relative paths. I agree with @mwmahlberg

[wz2b]

I'm having this same problem on an ubuntu system, specifically with subiquity. This app seems to do things to symlinks that it moves around, currently:

lrwxrwxrwx 1 root root     24 Oct 25 18:29 subiquity-debug.log -> subiquity-debug.log.2100
-rw-r--r-- 1 root root  66894 Oct 25 18:38 subiquity-debug.log.2100
lrwxrwxrwx 1 root root     23 Oct 25 18:29 subiquity-info.log -> subiquity-info.log.2100
-rw-r--r-- 1 root root  13168 Oct 25 18:38 subiquity-info.log.2100

I think the app is doing some kind of wacky log rotation where subiquity-info.log and subiquity-debug.log are symlinks to the latest file; when it rotates I think it will make *.2101 and update the symlink accordingly.

I don't really have a workaround at the moment, and I can't really think of a generic one anyway. I'm specifying a static config of /var/log/**/*.log which is why it picks up this symlink. In this case it wouldn't see the .2100 files so if promtail followed the symlinks it would have worked fine. An option "don't ever follow symlinks" might be okay, but following them would be better. Either way, it's filling my syslog up with these warnings which is annoying.

[miaojianbin]

I'm having this same problem on centos7 system.

[bparafina]

I'm also seeing this problem on ubuntu.