CODEWITHSUNDEEP
influxdbtelegraf
Ivan Burlutskiy
Ivan Burlutskiy

Reputation: 1623

Telegraf `docker_log` does not send all messages

I want to collect logs in influxdb from several go services with telegraf ``inputs.docker_log.

I found that influxdb contains not all records what I can see in docker service logs.

I did simple go script. And do several experiments with different delay.

package main

import (
    "time"

    "github.com/labstack/gommon/log"
)

func main() {

    log.SetLevel(log.DEBUG)
    for i := 0; i < 5; i++ {
        writeSomething()
        <-time.After(10 * time.Second)
    }
}

func writeSomething() {
    delay := 50 * time.Millisecond
    log.Debug("A")
    <-time.After(delay)

    log.Debug("B")
    <-time.After(delay)

    log.Debug("C")
    <-time.After(delay)

}

I found a problems when delay < 1 second.

For example. Delay = 50 Millisecond

Docker service logs shows all 3 variants (A, B, C) 5 times

liquineq_sender.1.0jvam7vg63cm@Ivan-Lenovo-ideapad    | {"time":"2019-09-26T13:47:17.115060311Z","level":"DEBUG","prefix":"-","file":"main.go","line":"20","message":"A"}
liquineq_sender.1.0jvam7vg63cm@Ivan-Lenovo-ideapad    | {"time":"2019-09-26T13:47:17.165383407Z","level":"DEBUG","prefix":"-","file":"main.go","line":"23","message":"B"}
liquineq_sender.1.0jvam7vg63cm@Ivan-Lenovo-ideapad    | {"time":"2019-09-26T13:47:17.21562549Z","level":"DEBUG","prefix":"-","file":"main.go","line":"26","message":"C"}

But I cant find some of them in influxdb: 

> select message from docker_log;
name: docker_log
time                message
----                -------
1569505640000000000 2019-09-26T13:47:18Z I! Starting Telegraf 1.12.2
1569505640000000000 t=2019-09-26T13:47:12+0000 lvl=info msg="Starting Grafana" logger=server version=6.3.0-pre commit=unknown-dev branch=master compiled=2019-06-21T08:57:10+0000
1569505640000000000 {"time":"2019-09-26T13:47:17.115060311Z","level":"DEBUG","prefix":"-","file":"main.go","line":"20","message":"A"}
1569505647000000000 {"time":"2019-09-26T13:47:27.265995126Z","level":"DEBUG","prefix":"-","file":"main.go","line":"20","message":"A"}
1569505657000000000 {"time":"2019-09-26T13:47:37.417263994Z","level":"DEBUG","prefix":"-","file":"main.go","line":"20","message":"A"}
1569505658000000000 {"time":"2019-09-26T13:47:37.517861048Z","level":"DEBUG","prefix":"-","file":"main.go","line":"26","message":"C"}
1569505668000000000 {"time":"2019-09-26T13:47:47.568291482Z","level":"DEBUG","prefix":"-","file":"main.go","line":"20","message":"A"}
1569505678000000000 {"time":"2019-09-26T13:47:57.71926933Z","level":"DEBUG","prefix":"-","file":"main.go","line":"20","message":"A"}

If increase delay up to 1 second, then influxdb contains all records.

Is there a way to setup telegraf / influxdb to parse milliseconds too?

Upvotes: 0

Views: 691

Answers (1)

Ivan Burlutskiy
Ivan Burlutskiy

Reputation: 1623

I solved a problem by adding following setting to telegraf config.

[agent]
  precision = "100ns"

Explanation:
Log accumulator of telegraf has method getTime. the method rounds log's time with some precision.

From AgentConfig: 

// By default or when set to "0s", precision will be set to the same
// timestamp order as the collection interval, with the maximum being 1s.
//   ie, when interval = "10s", precision will be "1s"
//       when interval = "250ms", precision will be "1ms"
// Precision will NOT be used for service inputs. It is up to each individual
// service input to set the timestamp at the appropriate precision.

Upvotes: 0

Related Questions