Watcher with proxy issue

bharat1 · September 18, 2019, 9:09am

Dear All,
I am trying to configure watcher with webhook API via Kibana to create alert. I am using proxy. The webhook is failing with "failed to send request to "servicenow:443/api..." and also with a "received 503 status code". Below are the configuration, any help will be appreciated

xpack.monitoring.enabled: true
xpack.monitoring.collection.enabled: true
xpack.monitoring.collection.interval: 60s
xpack.watcher.history.cleaner_service.enabled: true
xpack.http.proxy.host: 192.168.1.5
xpack.http.proxy.port: 3128
xpack.watcher.enabled: true
xpack.security.enabled: true

[2019-09-18T15:58:21,777][INFO ][o.e.x.w.c.h.HttpClient   ] [eshost] Using default proxy for http input and slack/pagerduty/webhook actions [192.168.1.5:3128]
[2019-09-18T18:33:17,008][INFO ][o.e.n.Node               ] [eshost] JVM arguments [-Xms2g, -Xmx2g, -XX:+UseConcMarkSweepGC, -XX:CMSInitiatingOccupancyFraction=75, -XX:+UseCMSInitiatingOccupancyOnly, -Des.networkaddress.cache.ttl=60, -Des.networkaddress.cache.negative.ttl=10, -Dhttp.proxyHost=192.168.1.5, -Dhttp.proxyPort=3128, -Dhttps.proxyHost=192.168.1.5, -Dhttps.proxyPort=3128, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -XX:-OmitStackTraceInFastThrow, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Dlog4j.shutdownHookEnabled=false, -Dlog4j2.disable.jmx=true, -Djava.io.tmpdir=/tmp/elasticsearch-18307886970072748061, -XX:+HeapDumpOnOutOfMemoryError, -XX:HeapDumpPath=/var/lib/elasticsearch, -XX:ErrorFile=/var/log/elasticsearch/hs_err_pid%p.log, -Xlog:gc*,gc+age=trace,safepoint:file=/var/log/elasticsearch/gc.log:utctime,pid,tags:filecount=32,filesize=64m, -Djava.locale.providers=COMPAT, -Dio.netty.allocator.type=pooled, -XX:MaxDirectMemorySize=1073741824, -Des.path.home=/usr/share/elasticsearch, -Des.path.conf=/etc/elasticsearch, -Des.distribution.flavor=default, -Des.distribution.type=rpm, -Des.bundled_jdk=true]
[2019-09-18T18:33:21,322][INFO ][o.e.x.w.c.h.HttpClient   ] [eshost] Using default proxy for http input and slack/pagerduty/webhook actions [192.168.1.5:3128]

below is the error I get

[2019-09-18T16:40:35,189][ERROR][o.e.x.w.a.w.ExecutableWebhookAction] [eshost] failed to execute action [61914b8b-be55-49f6-b87d-746ad124d870/webhook_1]
java.net.SocketTimeoutException: Read timed out
        at java.net.SocketInputStream.socketRead0(Native Method) ~[?:?]
        at java.net.SocketInputStream.socketRead(SocketInputStream.java:115) ~[?:?]
        at java.net.SocketInputStream.read(SocketInputStream.java:168) ~[?:?]
        at java.net.SocketInputStream.read(SocketInputStream.java:140) ~[?:?]
        at org.apache.http.impl.io.SessionInputBufferImpl.streamRead(SessionInputBufferImpl.java:137) ~[httpcore-4.4.11.jar:4.4.11]
        at org.apache.http.impl.io.SessionInputBufferImpl.fillBuffer(SessionInputBufferImpl.java:153) ~[httpcore-4.4.11.jar:4.4.11]
        at org.apache.http.impl.io.SessionInputBufferImpl.readLine(SessionInputBufferImpl.java:280) ~[httpcore-4.4.11.jar:4.4.11]
        at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:138) ~[httpclient-4.5.8.jar:4.5.8]
        at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:56) ~[httpclient-4.5.8.jar:4.5.8]
        at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:259) ~[httpcore-4.4.11.jar:4.4.11]
        at org.apache.http.impl.DefaultBHttpClientConnection.receiveResponseHeader(DefaultBHttpClientConnection.java:163) ~[httpcore-4.4.11.jar:4.4.11]
        at org.apache.http.impl.conn.CPoolProxy.receiveResponseHeader(CPoolProxy.java:157) ~[httpclient-4.5.8.jar:4.5.8]
        at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:273) ~[httpcore-4.4.11.jar:4.4.11]
        at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:125) ~[httpcore-4.4.11.jar:4.4.11]
        at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:272) ~[httpclient-4.5.8.jar:4.5.8]
        at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:186) ~[httpclient-4.5.8.jar:4.5.8]
        at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:89) ~[httpclient-4.5.8.jar:4.5.8]
        at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:110) ~[httpclient-4.5.8.jar:4.5.8]
        at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:185) ~[httpclient-4.5.8.jar:4.5.8]
        at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:72) ~[httpclient-4.5.8.jar:4.5.8]
        at org.elasticsearch.xpack.watcher.common.http.HttpClient.lambda$execute$1(HttpClient.java:242) ~[?:?]
        at java.security.AccessController.doPrivileged(AccessController.java:552) ~[?:?]
        at org.elasticsearch.xpack.core.common.socket.SocketAccess.doPrivileged(SocketAccess.java:32) ~[x-pack-core-7.3.1.jar:7.3.1]
        at org.elasticsearch.xpack.watcher.common.http.HttpClient.execute(HttpClient.java:242) ~[?:?]
        at org.elasticsearch.xpack.watcher.actions.webhook.ExecutableWebhookAction.execute(ExecutableWebhookAction.java:42) ~[?:?]
        at org.elasticsearch.xpack.core.watcher.actions.ActionWrapper.execute(ActionWrapper.java:163) [x-pack-core-7.3.1.jar:7.3.1]
        at org.elasticsearch.xpack.watcher.execution.ExecutionService.executeInner(ExecutionService.java:516) [x-pack-watcher-7.3.1.jar:7.3.1]
        at org.elasticsearch.xpack.watcher.execution.ExecutionService.execute(ExecutionService.java:309) [x-pack-watcher-7.3.1.jar:7.3.1]
        at org.elasticsearch.xpack.watcher.execution.ExecutionService.lambda$executeAsync$5(ExecutionService.java:410) [x-pack-watcher-7.3.1.jar:7.3.1]
        at org.elasticsearch.xpack.watcher.execution.ExecutionService$WatchExecutionTask.run(ExecutionService.java:605) [x-pack-watcher-7.3.1.jar:7.3.1]
        at org.elasticsearch.common.util.concurrent.ThreadContext$ContextPreservingRunnable.run(ThreadContext.java:688) [elasticsearch-7.3.1.jar:7.3.1]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
        at java.lang.Thread.run(Thread.java:835) [?:?]
[2019-09-18T16:40:36,166][DEBUG][o.e.x.s.a.e.ReservedRealm] [eshost] realm [reserved] authenticated user [kibana], with roles [[kibana_system]]

spinscale · September 20, 2019, 10:02am

can you share the full output of the Execute Watch API?

Also, what Elasticsearch version is this?

Last but not least, can you connect from the elasticsearch node using a curl call with the correct proxy settings? Can you show that output as well?

bharat1 · September 20, 2019, 10:56am

I am using Kibana GUI for creating the watcher. So I do not know how to get the API code of that created watcher.

Its 7.3

Yes using the proxy setting from same host from command line with curl

spinscale · September 24, 2019, 8:32am

did you restart elasticsearch after adding that setting?

The ID of the watch is in the UI.

The long string starting with ad28 is the ID

bharat1 · September 24, 2019, 9:35am

No let me try that and update

bharat1 · September 24, 2019, 5:12pm

I did restarted the ES service but no luck. When we save the webhook the state shows "OK" but when I try submitting "Send request", it gives same error and later after autorun as per schedule the state changes to error

I did not understood what do we need to do with ID that you mentioned? however that ID gave me hints to further troubleshoot using it thanks for that but still issue is not resolved

One thing noticed from log after I restart elasticsearch as below apart from log line "loaded module [x-pack-watcher]"

# - Watcher
#    - PUT / GET watch API are disabled, DELETE watch API continues to work
#    - Watches execute and write to the history
#    - The actions of the watches dont execute

I am using POST method and not PUT, secondly I have enabled as mentioned at start of the post
I also checked the o/p of GET API and the watcher ID is active i.e. true
and when I use execute API using watcher ID, it gives me

"root_cause" : [
{
  "type" : "Socket_timeout_exception"
  "reason" : "Read timed out" 
}
]

Not sure what is the solution. Am I missing something?

spinscale · September 25, 2019, 11:35am

Those are two different issues.

First, it seems that your license is expired. Is this possible? Check under Management > License Management

Second, this still looks as if the HTTP webhook does not work. Can you share the full output?

bharat1 · September 25, 2019, 12:00pm

The license is still valid and active.

do you mean the GET or PUT output?

bharat1 · September 25, 2019, 12:11pm

the GET query output as below

GET _watcher/watch/61914b8b-be55-49f6-b87d-746ad124d870
{
  "found" : true,
  "_id" : "61914b8b-be55-49f6-b87d-746ad124d870",
  "_version" : 1397,
  "_seq_no" : 1396,
  "_primary_term" : 2,
  "status" : {
    "state" : {
      "active" : true,
      "timestamp" : "2019-09-24T16:09:48.403Z"
    },
    "last_checked" : "2019-09-25T11:11:07.607Z",
    "last_met_condition" : "2019-09-25T11:11:07.607Z",
    "actions" : {
      "webhook_1" : {
        "ack" : {
          "timestamp" : "2019-09-24T16:09:48.403Z",
          "state" : "awaits_successful_execution"
        },
        "last_execution" : {
          "timestamp" : "2019-09-25T11:11:07.607Z",
          "successful" : false,
          "reason" : ""
        }
      }
    },
    "execution_state" : "executed",
    "version" : 1397
  },
  "watch" : {
    "trigger" : {
      "schedule" : {
        "interval" : "1h"
      }
    },
    "input" : {
      "search" : {
        "request" : {
          "search_type" : "query_then_fetch",
          "indices" : [
            "metricbeat-*"
          ],
          "rest_total_hits_as_int" : true,
          "body" : {
            "size" : 0,
            "query" : {
              "bool" : {
                "filter" : {
                  "range" : {
                    "@timestamp" : {
                      "gte" : "{{ctx.trigger.scheduled_time}}||-5m",
                      "lte" : "{{ctx.trigger.scheduled_time}}",
                      "format" : "strict_date_optional_time||epoch_millis"
                    }
                  }
                }
              }
            },
            "aggs" : {
              "metricAgg" : {
                "avg" : {
                  "field" : "system.memory.actual.used.pct"
                }
              }
            }
          }
        }
      }
    },
    "condition" : {
      "script" : {
        "source" : "if (ctx.payload.aggregations.metricAgg.value > params.threshold) { return true; } return false;",
        "lang" : "painless",
        "params" : {
          "threshold" : 0.15
        }
      }
    },
    "transform" : {
      "script" : {
        "source" : "HashMap result = new HashMap(); result.result = ctx.payload.aggregations.metricAgg.value; return result;",
        "lang" : "painless",
        "params" : {
          "threshold" : 0.15
        }
      }
    },
    "actions" : {
      "webhook_1" : {
        "webhook" : {
          "scheme" : "http",
          "host" : "https://example.alertingsystem.com",
          "port" : 443,
          "method" : "post",
          "path" : "/api/incident",
          "params" : { },
          "headers" : { },
          "auth" : {
            "basic" : {
              "username" : "abcd",
              "password" : "::xyz::"
            }
          },
          "body" : """
{
   "body": {
          "caller_id": "test user1",
          "description": "Test incident",
          "short_description": "Test incident",
          "impact": "3",
          "urgency": "3"
        }
}
"""
        }
      }
    },
    "metadata" : {
      "name" : "test-alert1",
      "watcherui" : {
        "trigger_interval_unit" : "h",
        "agg_type" : "avg",
        "time_field" : "@timestamp",
        "trigger_interval_size" : 1,
        "term_size" : 5,
        "time_window_unit" : "m",
        "threshold_comparator" : ">",
        "term_field" : null,
        "index" : [
          "metricbeat-*"
        ],
        "time_window_size" : 5,
        "threshold" : 0.15,
        "agg_field" : "system.memory.actual.used.pct"
      },
      "xpack" : {
        "type" : "threshold"
      }
    }
  }
}

bharat1 · September 25, 2019, 12:12pm

The above was for GET and below is for POST query output

POST _watcher/watch/61914b8b-be55-49f6-b87d-746ad124d870/_execute

{
  "_id" : "61914b8b-be55-49f6-b87d-746ad124d870_4122000f-c0f4-4e17-9b60-2ea7dbce2926-2019-09-25T12:04:50.434657Z",
  "watch_record" : {
    "watch_id" : "61914b8b-be55-49f6-b87d-746ad124d870",
    "node" : "RXXUiIZlTReFb6EQHwInnA",
    "state" : "executed",
    "user" : "elastic",
    "status" : {
      "state" : {
        "active" : true,
        "timestamp" : "2019-09-24T16:09:48.403Z"
      },
      "last_checked" : "2019-09-25T12:04:50.434Z",
      "last_met_condition" : "2019-09-25T12:04:50.434Z",
      "actions" : {
        "webhook_1" : {
          "ack" : {
            "timestamp" : "2019-09-24T16:09:48.403Z",
            "state" : "awaits_successful_execution"
          },
          "last_execution" : {
            "timestamp" : "2019-09-25T12:04:50.434Z",
            "successful" : false,
            "reason" : ""
          }
        }
      },
      "execution_state" : "executed",
      "version" : 1397
    },
    "trigger_event" : {
      "type" : "manual",
      "triggered_time" : "2019-09-25T12:04:50.434Z",
      "manual" : {
        "schedule" : {
          "scheduled_time" : "2019-09-25T12:04:50.434Z"
        }
      }
    },
    "input" : {
      "search" : {
        "request" : {
          "search_type" : "query_then_fetch",
          "indices" : [
            "metricbeat-*"
          ],
          "rest_total_hits_as_int" : true,
          "body" : {
            "size" : 0,
            "query" : {
              "bool" : {
                "filter" : {
                  "range" : {
                    "@timestamp" : {
                      "gte" : "{{ctx.trigger.scheduled_time}}||-5m",
                      "lte" : "{{ctx.trigger.scheduled_time}}",
                      "format" : "strict_date_optional_time||epoch_millis"
                    }
                  }
                }
              }
            },
            "aggs" : {
              "metricAgg" : {
                "avg" : {
                  "field" : "system.memory.actual.used.pct"
                }
              }
            }
          }
        }
      }
    },
    "condition" : {
      "script" : {
        "source" : "if (ctx.payload.aggregations.metricAgg.value > params.threshold) { return true; } return false;",
        "lang" : "painless",
        "params" : {
          "threshold" : 0.15
        }
      }
    },
    "metadata" : {
      "name" : "test-alert1",
      "watcherui" : {
        "trigger_interval_unit" : "h",
        "agg_type" : "avg",
        "time_field" : "@timestamp",
        "trigger_interval_size" : 1,
        "term_size" : 5,
        "time_window_unit" : "m",
        "threshold_comparator" : ">",
        "term_field" : null,
        "index" : [
          "metricbeat-*"
        ],
        "time_window_size" : 5,
        "threshold" : 0.15,
        "agg_field" : "system.memory.actual.used.pct"
      },
      "xpack" : {
        "type" : "threshold"
      }
    },
    "result" : {
      "execution_time" : "2019-09-25T12:04:50.434Z",
      "execution_duration" : 10017,
      "input" : {
        "type" : "search",
        "status" : "success",
        "payload" : {
          "_shards" : {
            "total" : 1,
            "failed" : 0,
            "successful" : 1,
            "skipped" : 0
          },
          "hits" : {
            "hits" : [ ],
            "total" : 964,
            "max_score" : null
          },
          "took" : 2,
          "timed_out" : false,
          "aggregations" : {
            "metricAgg" : {
              "value" : 0.191
            }
          }
        },
        "search" : {
          "request" : {
            "search_type" : "query_then_fetch",
            "indices" : [
              "metricbeat-*"
            ],
            "rest_total_hits_as_int" : true,
            "body" : {
              "size" : 0,
              "query" : {
                "bool" : {
                  "filter" : {
                    "range" : {
                      "@timestamp" : {
                        "gte" : "2019-09-25T12:04:50.434642Z||-5m",
                        "lte" : "2019-09-25T12:04:50.434642Z",
                        "format" : "strict_date_optional_time||epoch_millis"
                      }
                    }
                  }
                }
              },
              "aggs" : {
                "metricAgg" : {
                  "avg" : {
                    "field" : "system.memory.actual.used.pct"
                  }
                }
              }
            }
          }
        }
      },
      "condition" : {
        "type" : "script",
        "status" : "success",
        "met" : true
      },
      "transform" : {
        "type" : "script",
        "status" : "success",
        "payload" : {
          "result" : 0.191
        }
      },
      "actions" : [
        {
          "id" : "webhook_1",
          "type" : "webhook",
          "status" : "failure",
          "error" : {
            "root_cause" : [
              {
                "type" : "socket_timeout_exception",
                "reason" : "Read timed out"
              }
            ],
            "type" : "socket_timeout_exception",
            "reason" : "Read timed out"
          }
        }
      ]
    },
    "messages" : [ ]
  }
}

spinscale · September 25, 2019, 12:34pm

regarding the license. please check the preceding loglines, I assume that there is message that your license will expire soon then.

Regarding the webhook. Can you put the proxy settings directly in the webhook and see if that changes anything, like

"proxy" : { "host" : "whatever", "port": 1234 }

this still looks to me as if there is an issue connecting to the proxy from elasticsearch, but I don't see anything obvious.

bharat1 · September 25, 2019, 12:38pm

Where exactly should I insert this piece? As I am using kibana UI which does not gives option to put proxy server details, may this can be added in UI inbfuture release

spinscale · September 25, 2019, 12:47pm

I'm sorry that there is no easy way using the UI.

Use the console in kibana in combination with Get Watch API and the Put Watch API, when putting the watch you can add those parts to the webhook action

bharat1 · October 3, 2019, 5:33am

Thanks. Yes I was able to get this completed. Now the response code is 201. However I notice the ticket which gets created in the ticketing tool has empty details though after mentioning details about incident priority, description etc... not sure why

spinscale · October 7, 2019, 12:17pm

Again, feel free to share the Execute Watch API output for that watch or a watch history entry.

system · November 4, 2019, 12:17pm

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.