Inputs.tail grok debugging

Telegraf
,
1

I’ve been trying to get output from inputs.tail for awhile now and I am at the point where I’m hoping the community can help. I reviewed telegraf/plugins/parsers/grok at master · influxdata/telegraf · GitHub to learn about how the parser works, I then also developed a grok pattern at https://grokdebug.herokuapp.com/ to verify that it is able to parse logs from my system. I am still not getting anything out of telegraf.

Test telegraf.conf

# Read Nginx's basic status information (ngx_http_stub_status_module)
[[inputs.nginx]]
  ## An array of Nginx stub_status URI to gather stats.
  urls = ["http://127.0.0.1/server_status"]

  ## Optional TLS Config
  # tls_ca = "/etc/telegraf/ca.pem"
  # tls_cert = "/etc/telegraf/cert.pem"
  # tls_key = "/etc/telegraf/key.pem"
  ## Use TLS but skip chain & host verification
  # insecure_skip_verify = false

  ## HTTP response timeout (default: 5s)
  response_timeout = "5s"

[[outputs.file]]
  files = ["stdout"]

[[inputs.tail]]
  name_override = "nginx_access_log"
  files = ["/var/log/nginx/access.log"]
  from_beginning = true
  #pipe = false
  #watch_method = "inotify"
  data_format = "grok"
  grok_patterns = ["%{CUSTOM_LOG}"]
grok_custom_patterns = '''
CUSTOM_LOG %{NOTSPACE:host} %{IPORHOST:client_ip} - \[%{HTTPDATE:ts:ts-httpd}\] "(?:%{WORD:verb:tag} %{NOTSPACE:request}(?: HTTP/%{NUMBER:http_version:float})?|%{DATA:rawrequest})" %{NUMBER:resp_code:tag} %{NUMBER:resp_bytes:int} %{NUMBER:response_time_ns:duration} "%{DATA:referrer}" "%{DATA:agent}"
'''

Example log entry:

git.gec.im 185.191.171.11 - [20/Aug/2022:18:41:33 -0500] "GET /GRMrGecko/CocoaShare/action/star?redirect_to=%2FGRMrGecko%2FCocoaShare%2Fsrc%2Fcommit%2F9ebac37394dbb1f6fda47d01db50f806399348a9%2FResources%2FWebDav%2FWebDavAccountPane.xib HTTP/1.1" 405 0 0.003 "-" "Mozilla/5.0 (compatible; SemrushBot/7~bl; +http://www.semrush.com/bot.html)" "-"

Log configuration in nginx:

    log_format  main  '$http_host $remote_addr - [$time_local] "$request" '
                      '$status $body_bytes_sent $request_time "$http_referer" '
                      '"$http_user_agent" "$http_x_forwarded_for"';

    access_log  /var/log/nginx/access.log  main;

Test results:

# sudo -u telegraf /usr/bin/telegraf -config /etc/telegraf/telegraf.conf -config-directory /etc/telegraf/telegraf.d --debug --test
2022-08-21T00:56:58Z I! Starting Telegraf 1.23.4
2022-08-21T00:56:58Z I! Loaded inputs: nginx tail
2022-08-21T00:56:58Z I! Loaded aggregators: 
2022-08-21T00:56:58Z I! Loaded processors: 
2022-08-21T00:56:58Z W! Outputs are not used in testing mode!
2022-08-21T00:56:58Z I! Tags enabled: host=mainserver.gec.im
2022-08-21T00:56:58Z D! [agent] Initializing plugins
2022-08-21T00:56:58Z D! [agent] Starting service inputs
2022-08-21T00:56:58Z D! [agent] Stopping service inputs
2022-08-21T00:56:58Z D! [agent] Input channel closed
> nginx,host=mainserver.gec.im,port=80,server=127.0.0.1 accepts=41290i,active=8i,handled=41290i,reading=0i,requests=85149i,waiting=4i,writing=4i 1661043418000000000
2022-08-21T00:56:58Z D! [agent] Stopped Successfully

I double checked that the telegraf user is able to tail the log file, not sure where to go for debug from here. I thought enabling debug in telegraf would output debug details but it only outputs metrics sent.

2

I’m not aware of a way to “debug” what happens at runtime inside a plugin, the best you can do is to keep trying until it works… From what I’ve seen the pattern should work correctly.

You are already “debugging” in the best possible way (that input only, plus the file output to see the results).

From what I see you are getting something in the output…

nginx,host=mainserver.gec.im,port=80,server=127.0.0.1 accepts=41290i,active=8i,handled=41290i,reading=0i,requests=85149i,waiting=4i,writing=4i 1661043418000000000

What do you expect to get? more lines?
is the timestamp the one from the log? (from the examples it should be named timestamp not ts, meaning {HTTPDATE:timestamp:ts-httpd})

3

I got the use of ts instead of timestamp from telegraf/influx_patterns.go at master · influxdata/telegraf · GitHub and just tested to see if using timestamp will work and it does not.

I did find a way to better trouble shoot which lead to me finding the problem. I put my test config in /etc/telegraf/telegraf-test.conf and used the following to test.

sudo -u telegraf /usr/bin/telegraf -config /etc/telegraf/telegraf-test.conf --test

My problem ended up being that the /var/log/nginx folder disallowed telegraf user from accessing the directory. Even though the file was accessible, telegraf didn’t like that the directory wasn’t. I added telegraf to the nginx group to fix this.

4

Glad you found the issue.

About ts vs timestamp I got it form the samples of the grok parser here… I’ll do some tests too to see if the docs are correct or not