Beats: Invalid CRI error on Filebeat with docker log join enabled

[wflyer]

• Version: 6.4.0
• Operating System: Ubuntu 16.04 LTS
• Steps to Reproduce:

On filebeat 6.4.0, with docker combine_partials enabled (which is default), sometimes docker log suddenly can't be processed such as below:

2018-08-31T16:29:27.810+0900    ERROR   log/harvester.go:278    Read line error: invalid CRI log; File: /var/lib/docker/containers/c37ca2c20d3a79d5430f2c967b104d6995f425ceb387394e19cc74218a505a1e/c37ca2c20d3a79d5430f2c967b104d6995f425ceb387394e19cc74218a505a1e-json.log

What I found until now is, the registry of the docker log file is incorrect, which is smaller than current file offset even when all log messages were processed.
(the docker container has some logs larger than 16k)

So, the docker containers that actively printing logs don't experience this issue.
But when some logs closed due to infrequent access (larger than close_inactive), they experience this kind of issue when it re-opened.
Also, I could reproduce this error even when I restart filebeat (eg.service filebeat restart) maybe because the harvester starts to read from the specified incorrect offset written in the registry file.

[exekias]

Thank you for opening this, this seems related: https://discuss.elastic.co/t/read-line-error-invalid-cri-log-filbeat-halts-processing-logs/146284/5

[exekias]

@wflyer can you confirm that a big close_inactive makes the error disappear? Of course this is not a solution but would help us to understand what's going on

[wflyer]

@exekias Yes. For now, I've set close_inactive: 48h which keeps all of my docker container logs in an active state, and the error not yet observed for those instances.

After reviewing codes and https://github.com/elastic/beats/pull/6967, I think the root cause is message.Bytes is not added up when message.Content is appended so the harvester increase file offset only for message.Bytes of the first partial log. If you also think that this is the reason, I'll submit a relevant PR.

[exekias]

that sounds about right indeed! thank you for having a look @wflyer! :tada: Let us know if we can help with that PR, it would be awesome to have this in for the next patch version

[marco-admyre]

I see this problem with filebeat 7.1.1.

2019-06-19T12:21:36.867Z ERROR log/harvester.go:281 Read line error: invalid CRI log format; File: /var/lib/docker/containers/555502743facf92d9fe698a611979d4d5bfcf6634f2d3e35252c898890614107/555502743facf92d9fe698a611979d4d5bfcf6634f2d3e35252c898890614107-json.log

[GMartinez-Sisti]

I'm having this issue with docker.elastic.co/beats/filebeat:7.2.0 @sha256:8a1043fff877f096b8abc1cf10ca4aabafead7ec383e2eb8c90cac026de5d608 running in Kubernetes v1.12.9 as DaemonSet:

{"level":"warn","timestamp":"2019-08-01T12:46:38.940Z","caller":"beater/filebeat.go:358","message":"Filebeat is unable to load the Ingest Node pipelines for the configured modules because the Elasticsearch output is not configured/enabled. If you have already loaded the Ingest Node pipelines or are using Logstash pipelines, you can ignore this warning."}
{"level":"warn","timestamp":"2019-08-01T12:46:38.940Z","logger":"cfgwarn","caller":"kubernetes/kubernetes.go:55","message":"BETA: The kubernetes autodiscover is beta"}
{"level":"error","timestamp":"2019-08-01T12:48:15.848Z","caller":"log/harvester.go:280","message":"Read line error: invalid CRI log format; File: /var/lib/docker/containers/310b977100ac31dd4ca0c45a6a8e4080f1559fa0c94e15fb66cf6f18fe1e05ed/310b977100ac31dd4ca0c45a6a8e4080f1559fa0c94e15fb66cf6f18fe1e05ed-json.log"}
{"level":"error","timestamp":"2019-08-01T12:49:17.866Z","caller":"log/harvester.go:280","message":"Read line error: invalid CRI log format; File: /var/lib/docker/containers/310b977100ac31dd4ca0c45a6a8e4080f1559fa0c94e15fb66cf6f18fe1e05ed/310b977100ac31dd4ca0c45a6a8e4080f1559fa0c94e15fb66cf6f18fe1e05ed-json.log"}
{"level":"error","timestamp":"2019-08-01T12:49:43.101Z","caller":"log/harvester.go:280","message":"Read line error: invalid CRI log format; File: /var/lib/docker/containers/310b977100ac31dd4ca0c45a6a8e4080f1559fa0c94e15fb66cf6f18fe1e05ed/310b977100ac31dd4ca0c45a6a8e4080f1559fa0c94e15fb66cf6f18fe1e05ed-json.log"}