Splunk-connect-for-kubernetes: Certain metrics unavailable after a connection timeout

[cwebbtw]

What happened:

After a timeout connecting to splunk, specific metrics are no longer sent to splunk even though the server is readily available.

A log dump from the running pod (splunk metrics aggregator) indicates that this happened on the 12th July.

2019-07-12 09:45:21 +0000 [error]: #0 Unexpected error raised. Stopping the timer. title=:resource_usage_scraper error_class=RestClient::Exceptions::OpenTimeout error="Timed out connecting to server"
  2019-07-12 09:45:21 +0000 [error]: #0 /usr/lib/ruby/gems/2.5.0/gems/rest-client-2.0.2/lib/restclient/request.rb:731:in `rescue in transmit'
  2019-07-12 09:45:21 +0000 [error]: #0 /usr/lib/ruby/gems/2.5.0/gems/rest-client-2.0.2/lib/restclient/request.rb:642:in `transmit'
  2019-07-12 09:45:21 +0000 [error]: #0 /usr/lib/ruby/gems/2.5.0/gems/rest-client-2.0.2/lib/restclient/request.rb:145:in `execute'
  2019-07-12 09:45:21 +0000 [error]: #0 /usr/lib/ruby/gems/2.5.0/gems/rest-client-2.0.2/lib/restclient/request.rb:52:in `execute'
  2019-07-12 09:45:21 +0000 [error]: #0 /usr/lib/ruby/gems/2.5.0/gems/rest-client-2.0.2/lib/restclient/resource.rb:51:in `get'
  2019-07-12 09:45:21 +0000 [error]: #0 /usr/lib/ruby/gems/2.5.0/gems/fluent-plugin-k8s-metrics-agg-1.1.0/lib/fluent/plugin/in_kubernetes_metrics_aggregator.rb:536:in `scrape_resource_usage_metrics'
  2019-07-12 09:45:21 +0000 [error]: #0 /usr/lib/ruby/gems/2.5.0/gems/fluentd-1.4.0/lib/fluent/plugin_helper/timer.rb:80:in `on_timer'
  2019-07-12 09:45:21 +0000 [error]: #0 /usr/lib/ruby/gems/2.5.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run_once'
  2019-07-12 09:45:21 +0000 [error]: #0 /usr/lib/ruby/gems/2.5.0/gems/cool.io-1.5.3/lib/cool.io/loop.rb:88:in `run'
  2019-07-12 09:45:21 +0000 [error]: #0 /usr/lib/ruby/gems/2.5.0/gems/fluentd-1.4.0/lib/fluent/plugin_helper/event_loop.rb:93:in `block in start'
  2019-07-12 09:45:21 +0000 [error]: #0 /usr/lib/ruby/gems/2.5.0/gems/fluentd-1.4.0/lib/fluent/plugin_helper/thread.rb:78:in `block in thread_create'
2019-07-12 09:45:21 +0000 [error]: #0 Timer detached. title=:resource_usage_scraper

Some of the metrics that are not available are:

kube.node.memory.allocatable
kube.cluster.cpu.request
kube.cluster.cpu.limit

What you expected to happen:

Metrics to be sent to splunk when the host is available again. Right now, the pod is in a ready state, but the process running inside it is not collecting logs and forwarding them to splunk.

How to reproduce it (as minimally and precisely as possible):

Restrict the pod from being able to communicate with the host so that the connection times out.

Environment:

• Splunk metrics aggregator image:

splunk/k8s-metrics-aggr:1.1.0

• Kubernetes version (use kubectl version):

v1.13.5

[chaitanyaphalak]

Hey @cwebbtw, can you post the buffer setting for the configmap of metrics aggregator. I suspect we might be running out of buffer.

[cwebbtw]

@chaitanyaphalak thank you for your response, please see the buffer section:

  <buffer>
    @type memory
    chunk_limit_records 10000
    chunk_limit_size 100m
    flush_interval 5s
    flush_thread_count 1
    overflow_action block
    retry_max_times 3
    total_limit_size 400m
  </buffer>

Given that the error message suggests a connection timed out and the timer stopped, is it correct that the pod should continue to be alive?

[chaitanyaphalak]

@cwebbtw if you look at the implementation https://github.com/splunk/fluent-plugin-k8s-metrics-agg/blob/develop/lib/fluent/plugin/in_kubernetes_metrics_aggregator.rb#L541-L551
its designed to continue to stay alive. But I am open to suggestions. Let me know your thoughts :)

[cwebbtw]

@chaitanyaphalak It seems as if you're catching StandardError on line 549 , however, given the error being raised is an Unexpected Error, as seen in the initial log posted:

2019-07-12 09:45:21 +0000 [error]: #0 Unexpected error raised. Stopping the timer. title=:resource_usage_scraper error_class=RestClient::Exceptions::OpenTimeout error="Timed out connecting to server"

I'm inclined to believe the exception handler to keep the timer alive is not being hit, as evidenced by Timer Detached in the error seen in the initial log:

2019-07-12 09:45:21 +0000 [error]: #0 Timer detached. title=:resource_usage_scraper

It's my thoughts that a connection timeout shouldn't detach the timer and should be caught and logged. The exception being thrown that causes the error is 'https://www.rubydoc.info/gems/rest-client/RestClient/Exceptions/OpenTimeout'

[cwebbtw]

@chaitanyaphalak Any feedback for this? I'm assuming that this would be a problem for others too.

[chaitanyaphalak]

@cwebbtw it looks like there is not much we can do here, except fix the bug :)
I would be happy to review a PR for you on https://github.com/splunk/fluent-plugin-k8s-metrics-agg.

Thanks

[cwebbtw]

Hey @chaitanyaphalak, I'll see what I can come up with in a PR, thanks!

[chaitanyaphalak]

@cwebbtw let me know if you need help with setting up a dev environment for the PR, I want to enable the community to contribute to the project :)

Thanks

[cwebbtw]

2019-09-04 11:41:09 +0000 [error]: #0 Unexpected error raised. Stopping the timer. title=:resource_usage_scraper error_class=SocketError error="Failed to open TCP connection to <redacted>:443 (getaddrinfo: Try again)"

I'm unable to dedicate any time to a PR right now, but this seems like a pretty serious issue - is it likely to be added to a milestone at any time soon?

[chaitanyaphalak]

We will consider it for a future release for the mertics-agg plugin.

[KrzysztofKowalczyk]

OpenTimeout in RestClient extends
RestClient::Exceptions::OpenTimeout < RestClient::Exceptions::Timeout < RestClient::RequestTimeout < RestClient::Exception < RuntimeError < StandardError

Hence the exception is a StandardError so not sure why it is not handled in the mentioned catch

[KrzysztofKowalczyk]

Our theory is that the get methods throw exception which is not being handled at all:

https://github.com/splunk/fluent-plugin-k8s-metrics-agg/blob/develop/lib/fluent/plugin/in_kubernetes_metrics_aggregator.rb#L363-L366`

[chaitanyaphalak]

fixed as part of https://github.com/splunk/fluent-plugin-k8s-metrics-agg/pull/33