stdin support?

[filippog]

trafficstars

hi, thanks for mtail, looks really useful! Is reading from stdin something supported or considered? the use case I have in mind would be programs that don't log to file but in a ring memory buffer (e.g. varnish)

thanks!

[jaqx0r]

This is a good idea, I think I can add support for reading from a file descriptor instead of only stdin. The only caveat is that this changes the reader to need to keep up with the log stream, where currently it does not (by being buffered on the file system.)

But by removing the filesystem, we can potentially improve performance by not waiting on disk seeks.

Thanks! I am not sure how soon I could implement this though. On 16 May 2015 20:42, "Filippo Giunchedi" [email protected] wrote:

hi, thanks for mtail, looks really useful! Is reading from stdin something supported or considered? the use case I have in mind would be programs that don't log to file but in a ring memory buffer (e.g. varnish)

thanks!

— Reply to this email directly or view it on GitHub https://github.com/google/mtail/issues/3.

[filippog]

true! Yeah in practice I'd say the reader won't be a bottleneck for most cases, also there shouldn't be a lot of memory required for buffering while reading (?)

anyways no problem on the timeline, thanks for the quick reply!

[jaqx0r]

I'm thinking about this some more. How does varnish emit its logs that you'd want mtail to read from stdin? Would you want to open a named pipe or unix socket, or open a file descriptor?

If you can give me more information about how you think it would work that would be very helpful.

[filippog]

so in this particular case varnishlog (https://www.varnish-cache.org/docs/3.0/reference/varnishlog.html) would read log entries from shared memory ring buffer and output those on stdout, e.g.

   18 TxProtocol   c HTTP/1.1
   18 TxStatus     c 204
   18 TxResponse   c Cache miss
   18 TxHeader     c Server: Varnish
   18 TxHeader     c Accept-Ranges: bytes

Also there would be cross-line correlation to do for some things, so it might be more complicated than I initially thought.

Anyways, do you still see value in accepting stdin? thanks!

[jaqx0r]

The mtail language supports temporary state, iirc, so you could write a program that handles multiline messages if there is a common term to correlate with.

Right now I am thinking of generalising inputs as taking an arbitrary open file descriptor, so reading stdin would be supported. I'm still trying to imagine how it would be configured. On 2 Jun 2015 9:46 am, "Filippo Giunchedi" [email protected] wrote:

so in this particular case varnishlog ( https://www.varnish-cache.org/docs/3.0/reference/varnishlog.html) would read log entries from shared memory ring buffer and output those on stdout, e.g.

18 TxProtocol c HTTP/1.1 18 TxStatus c 204 18 TxResponse c Cache miss 18 TxHeader c Server: Varnish 18 TxHeader c Accept-Ranges: bytes

Also there would be cross-line correlation to do for some things, so it might be more complicated than I initially thought.

Anyways, do you still see value in accepting stdin? thanks!

— Reply to this email directly or view it on GitHub https://github.com/google/mtail/issues/3#issuecomment-107748299.

[jaqx0r]

BTW thanks the link to the varnish docs. On 2 Jun 2015 1:24 pm, "Jamie Wilkinson" [email protected] wrote:

The mtail language supports temporary state, iirc, so you could write a program that handles multiline messages if there is a common term to correlate with.

Right now I am thinking of generalising inputs as taking an arbitrary open file descriptor, so reading stdin would be supported. I'm still trying to imagine how it would be configured. On 2 Jun 2015 9:46 am, "Filippo Giunchedi" [email protected] wrote:

so in this particular case varnishlog ( https://www.varnish-cache.org/docs/3.0/reference/varnishlog.html) would read log entries from shared memory ring buffer and output those on stdout, e.g.

18 TxProtocol c HTTP/1.1 18 TxStatus c 204 18 TxResponse c Cache miss 18 TxHeader c Server: Varnish 18 TxHeader c Accept-Ranges: bytes

Also there would be cross-line correlation to do for some things, so it might be more complicated than I initially thought.

Anyways, do you still see value in accepting stdin? thanks!

— Reply to this email directly or view it on GitHub https://github.com/google/mtail/issues/3#issuecomment-107748299.

[jaqx0r]

I've added a flag -logfds that you can pass numerical file descriptors to, e.g.:

mtail -progs examples -logfds 0

which will load the programs in the examples directory, and open stdin for tailing logs.

It's a bit rough at the moment, so more feedback appreciated -- open new bugs please!

[filippog]

:+1: I'll give it a try, thanks @jaqx0r !

[b4ldr]

@jaqx0r thanks for your work and this tool. I notice that this feature was removed about a year ago[1] which I have just noticed after upgrading. Do you have more information on why this 'can't ever work'. As it appears to be working for us.

[1]https://github.com/google/mtail/commit/8cd80a91576f1fba57832049bd6ae39d08ffe3fd

[jaqx0r]

Can you show me how you run mtail such that it does work?

As this was a year ago, I don't remember why I decided it didn't work. So, if you can show me how to use it, then I will put the feature back in.

On Fri, 12 Jul 2019 at 00:56, John Bond [email protected] wrote:

@jaqx0r https://github.com/jaqx0r thanks for your work and this tool. I notice that this feature was removed about a year ago[1] which I have just noticed after upgrading. Do you have more information on why this 'can't ever work'. As it appears to be working for us.

[1]8cd80a9 https://github.com/google/mtail/commit/8cd80a91576f1fba57832049bd6ae39d08ffe3fd

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/google/mtail/issues/3?email_source=notifications&email_token=AAXFX66CUIHFTZY4B3CO5KLP65CX7A5CNFSM4BDSYXV2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODZW65YQ#issuecomment-510521058, or mute the thread https://github.com/notifications/unsubscribe-auth/AAXFX6YBCXTTZXTLZF2FL33P65CX7ANCNFSM4BDSYXVQ .

[b4ldr]

Thanks for getting back and also it seems my colleague filippog (who originally opened this issue) also contacted you. I think its best to continue the discussion here and save you answering both of us. To answer your question we run the program with the following

/usr/bin/varnishncsa -n frontend -F "${FMT}" | mtail -progs "${PROGS}" -logfds 0

https://github.com/wikimedia/puppet/blob/production/modules/varnish/files/varnishmtail#L23

[jaqx0r]

Aha I see now how it works. Thanks for that and the link to the puppet module.

The fds 0 1 and 2 are the only ones mtail can possibly use because they're created by the OS; I had removed the functionality because I had believed that a parent process would be executing mtail by itself, and passing a file descriptor to the child process, and then telling mtail what it was with this flag.

So... it does in fact work that way, because stdin is always fd 0.

I'll add it back, but in the meantime does trying to open -log /dev/stdin work ?

On Mon., 15 Jul. 2019, 19:57 John Bond, [email protected] wrote:

Thanks for getting back and also it seems my colleague filippog (who originally opened this issue) also contacted you. I think its best to continue the discussion here and save you answering both of us. To answer your question we run the program with the following

/usr/bin/varnishncsa -n frontend -F "${FMT}" | mtail -progs "${PROGS}" -logfds 0

https://github.com/wikimedia/puppet/blob/production/modules/varnish/files/varnishmtail#L23

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/google/mtail/issues/3?email_source=notifications&email_token=AAXFX62PEIQ2DMLJIJYQFU3P7RCYHA5CNFSM4BDSYXV2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGODZ5HGTI#issuecomment-511341389, or mute the thread https://github.com/notifications/unsubscribe-auth/AAXFX645EMHGZHHYE6WKWK3P7RCYHANCNFSM4BDSYXVQ .

[b4ldr]

I have had a quick look at it seems [to me] that -log /dev/stdin does work however i want filippog to confirm as I'm not that familiar with mtail/Prometheus etc. It it does work as it seems then we will update our usage to use -logs, I have already prepared the PR[1]

Thanks

[1]https://gerrit.wikimedia.org/r/#/c/operations/puppet/+/523739

[filippog]

I can confirm that -logs /dev/stdin does indeed work as intended!

[b4ldr]

@jaqx0r with filippog's confirmation i will merge my change tomorrow and will use -log /dev/stdin as such there is no need to add -logfds back if its just us asking for it

Thanks

[jaqx0r]

Great. I'm not certain that /dev/stdin is on all platforms so I want to add '-' as a special filename that means stdin, like many gnu tools do.

On Thu., 18 Jul. 2019, 04:22 John Bond, [email protected] wrote:

@jaqx0r https://github.com/jaqx0r with filippog's confirmation i will merge my change tomorrow and will use -log /dev/stdin as such there is no need to add -logfds back if its just us asking for it

Thanks

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/google/mtail/issues/3?email_source=notifications&email_token=AAXFX64H3CMKTB2TETUOE5TP75PNJA5CNFSM4BDSYXV2YY3PNVWWK3TUL52HS4DFVREXG43VMVBW63LNMVXHJKTDN5WW2ZLOORPWSZGOD2GE4GA#issuecomment-512511512, or mute the thread https://github.com/notifications/unsubscribe-auth/AAXFX63EGDLA5B6BWLTW7XLP75PNJANCNFSM4BDSYXVQ .

[slomo]

When using /dev/stdin as an parameter I am seeing those errors in the log:

I0312 05:41:25.819354   22098 store.go:107] Running Store.Expire()
I0312 06:41:25.819325   22098 store.go:107] Running Store.Expire()
I0312 07:41:25.819406   22098 tail.go:253] read /dev/stdin: file already closed
I0312 07:41:25.819556   22098 store.go:107] Running Store.Expire()
I0312 07:41:25.822624   22098 log_watcher.go:254] Found this processor in watched list
I0312 07:41:25.822852   22098 log_watcher.go:249] No abspath in watched list, added new one for /dev/stdin
I0312 07:41:25.822861   22098 tail.go:300] Tailing /dev/stdin
W0312 08:18:12.649910   22098 tail.go:242] Internal error finding file handle for "/dev/null" after create
W0312 08:18:12.651290   22098 tail.go:242] Internal error finding file handle for "/dev/null" after create
W0312 08:18:12.651341   22098 tail.go:242] Internal error finding file handle for "/dev/null" after create
... hundred times same error message ...
W0312 08:18:12.657091   22098 tail.go:242] Internal error finding file handle for "/dev/null" after create
I0312 08:41:25.819368   22098 store.go:107] Running Store.Expire()

Am I doing somehing wrong? My starting command looks like this:

/usr/bin/journalctl  -o cat -f -n 0 | /opt/mtail/mtail_3.0.0-rc34 -progs progs -logs /dev/stdin -logtostderr

EDIT: These are the logs during startup:

I0312 10:42:56.397491   66735 main.go:100] mtail version v3.0.0-rc34 git revision 7b4270cb6e8b6ed1f2febe48e370cb68d38681f9 go version go1.12.15 go arch amd64 go os linux
I0312 10:42:56.397587   66735 main.go:101] Commandline: ["/opt/mtail/mtail_3.0.0-rc34" "-progs" "/opt/mtail" "-logs" "/dev/stdin" "-logtostderr"]
I0312 10:42:56.398401   66735 log_watcher.go:249] No abspath in watched list, added new one for progs
I0312 10:42:56.398759   66735 checker.go:214] declaration of capture group reference `total_time' at haproxy.mtail:5:1-179 appears to be unused
I0312 10:42:56.398775   66735 checker.go:214] declaration of capture group reference `total_time' at haproxy.mtail:5:1-179 appears to be unused
I0312 10:42:56.398864   66735 loader.go:229] Loaded program haproxy.mtail
I0312 10:42:56.398902   66735 log_watcher.go:249] No abspath in watched list, added new one for /dev
I0312 10:42:56.398929   66735 log_watcher.go:249] No abspath in watched list, added new one for /dev/stdin
I0312 10:42:56.398935   66735 log_watcher.go:254] Found this processor in watched list
I0312 10:42:56.398965   66735 log_watcher.go:254] Found this processor in watched list
I0312 10:42:56.398974   66735 tail.go:300] Tailing /dev/stdin
I0312 10:42:56.399089   66735 tail.go:446] Starting log handle expiry loop every 1h0m0s
I0312 10:42:56.399511   66735 store.go:136] Starting metric store expiry loop every 1h0m0s
I0312 10:42:56.399262   66735 mtail.go:321] Listening on [::]:3903

[jaqx0r]

In #479 we're adding functionality to parse the log path pattern, once that has landed I'll add the ability to pass - like I mentioned earlier.

[jaqx0r]

@slomo Please can you try again with a current mtail ? I think rc34 was using inotify and also polling all the files in the parent directory, which is why you were seeing /dev/null show up. Now mtail doesn't do that, so I'd be interested to know if you get the same behaviour.