get docker log stream in correct order

Question

I've tried a couple of log collection services now, like logspout/papertrail and fluentd/elasticsearch, but the results don't always show up in the correct order, which can make debugging difficult. An example is with a Node.js application, a console.log command which results in multiple lines, or an error with its stack trace. The lines all show up with the same timestamp, and I guess the log collection services have no way to know which order to display those. Is there a way to add millisecond precision? Or some other way to make sure they are displayed in the same order as if I did a docker logs command?

Update: I haven't looked into it, but I saw something about fluent or elasticsearch supporting millisecond+ accuracy by default in a newer version

score 1 · Answer 1 · edited May 23 '17 at 12:31

1

In my understanding, you have 2 options:

Increase time stamp precision (like you did); or
Use log storage which can maintain the order of data. For example MongoDB. The log collection concept is described in another stackoverflow post.

edited May 23 '17 at 12:31

Community

1
1

answered May 27 '15 at 10:29

Miska Kaipiainen

11
3

would that involve checking the log files manually somewhere? do you have an example of how that would work? – Reese May 27 '15 at 16:53
The log storage approach I'm thinking is very well described in another [stackoverflow question](http://stackoverflow.com/questions/10525725/which-nosql-database-should-i-use-for-logging/13428282#13428282) The real problem with docker log collection comes when your containerized application is growing. In large scale deployments you might have load balancers and multiple containers (micro service architecture with scaling). Therefore you'll need to aggregate log data into "service" log streams to make any sense. Example of such log collection: [kontena](https://github.com/kontena/kontena) – Miska Kaipiainen May 28 '15 at 08:02

score 0 · Answer 2 · edited May 23 '17 at 12:23

I found a workaround for fluentd in this answer, though I'd still like a real solution

Here is my modified td-agent.conf, for use in the fluentd-es-image. It adds the time_nano field, which can be sorted on

<source>
  type tail
  format json
  time_key time
  path /varlog/containers/*.log
  pos_file /varlog/es-containers.log.pos
  time_format %Y-%m-%dT%H:%M:%S.%L%Z
  tag cleanup.reform.*
  read_from_head true
</source>

<match cleanup.**>
   type record_reformer
   time_nano ${t = Time.now; ((t.to_i * 1000000000) + t.nsec).to_s}
   tag ${tag_suffix[1]}
</match>


<match reform.**>
  type record_reformer
  enable_ruby true
  tag kubernetes.${tag_suffix[3].split('-')[0..-2].join('-')}
</match>

<match kubernetes.**>
   type elasticsearch
   log_level info
   include_tag_key true
   host elasticsearch-logging.default
   port 9200
   logstash_format true
   flush_interval 5s
   # Never wait longer than 5 minutes between retries.
   max_retry_wait 300
   # Disable the limit on the number of retries (retry forever).
   disable_retry_limit
</match>

<source>
  type tail
  format none
  path /varlog/kubelet.log
  pos_file /varlog/es-kubelet.log.pos
  tag kubelet
</source>

<match kubelet>
   type elasticsearch
   log_level info
   include_tag_key true
   host elasticsearch-logging.default
   port 9200
   logstash_format true
   flush_interval 5s
   # Never wait longer than 5 minutes between retries.
   max_retry_wait 300
   # Disable the limit on the number of retries (retry forever).
   disable_retry_limit
</match>

get docker log stream in correct order

2 Answers2