Winlogbeat transport problem on port 80 through reverse proxy to Elasticsearch

UnclePhil · February 4, 2016, 1:14pm

Hello,
I've just installed winlogbeat on scripting server, and It seems that a transport to elasticsearch on another port than 9200 is impossible
I tested it with our standard 80 (working with powershell scripting on the same server), and i receive some error in the logs

Did any one have a solution about this, and is beat transport really possible on another port ??

Best regards

Ph Koenig

ruflin · February 4, 2016, 1:37pm

Can you share your config file and the errors you got in the log file?

Update: Just saw your issue here: https://github.com/elastic/beats/issues/924 Please do not double post.

UnclePhil · February 4, 2016, 2:21pm

here, the yml file

winlogbeat:
  registry_file: C:/ProgramData/winlogbeat/.winlogbeat.yml


  event_logs:
    - name: Application
    - name: Security
    - name: System
    - name: Windows PowerShell

output:
  elasticsearch:
    hosts: ["elasticsearch.irisnet.be:80"]

    index: "winlogbeat"

logging:
  to_files: true
  files:
    path: C:/ProgramData/winlogbeat/Logs

  level: info

============================
a simple call to the url with powershell (I know i need to upgrade the ES )

PS C:\Users\Administrator> Invoke-WebRequest

cmdlet Invoke-WebRequest at command pipeline position 1
Supply values for the following parameters:
Uri: http://elasticsearch.irisnet.be:80

StatusCode : 200
StatusDescription : OK
Content : {
"status" : 200,
"name" : "lg2",
"cluster_name" : "zelastinsearch",
"version" : {
"number" : "1.6.2",
"build_hash" : "622039121e53e5f520b5ff8720fdbd3d0cb5326b",
"build_timestamp" ...
RawContent : HTTP/1.1 200 OK
Content-Length: 332
Content-Type: application/json; charset=UTF-8

                {
                  "status" : 200,
                  "name" : "lg2",
                  "cluster_name" : "zelastinsearch",
                  "version" : {
                    "number" : "1.6.2"...

Forms : {}
Headers : {[Content-Length, 332], [Content-Type, application/json; charset=UTF-8]}
Images : {}
InputFields : {}
Links : {}
ParsedHtml : System.__ComObject
RawContentLength : 332

UnclePhil · February 4, 2016, 2:22pm

and

Here, the return of a winlogbeat run in debug mode

2016/02/04 14:10:57.126642 publish.go:109: DBG Publish: {
"@timestamp": "2016-02-04T14:08:57.946Z",
"beat": {
"hostname": "SVIMSCAVW001",
"name": "SVIMSCAVW001"
},
"computer_name": "SVIMSCAVW001",
"count": 1,
"event_id": 7036,
"level": "Information",
"log_name": "System",
"message": "The winlogbeat service entered the stopped state.",
"record_number": "26635",
"source_name": "Service Control Manager",
"type": "wineventlog"
}
2016/02/04 14:10:57.130642 output.go:87: DBG output worker: publish 1 events
2016/02/04 14:10:57.130642 client.go:265: DBG ES Ping(url=http://elasticsearch.irisnet.be:80, timeout=1m30s)
2016/02/04 14:10:57.133642 client.go:270: DBG Ping request failed with: 503 Service Unavailable
2016/02/04 14:10:57.133642 single.go:126: INFO Connecting error publishing events (retrying): 503 Service Unavailable
2016/02/04 14:10:57.134642 single.go:152: INFO send fail
2016/02/04 14:10:57.134642 single.go:159: INFO backoff retry: 1s
2016/02/04 14:10:58.104698 wineventlog.go:78: DBG WinEventLog[Application] No more events
2016/02/04 14:10:58.104698 winlogbeat.go:227: DBG EventLog[Application] Read() returned 0 records
2016/02/04 14:10:58.105698 wineventlog.go:78: DBG WinEventLog[Security] No more events
2016/02/04 14:10:58.105698 winlogbeat.go:227: DBG EventLog[Security] Read() returned 0 records
2016/02/04 14:10:58.107698 wineventlog.go:78: DBG WinEventLog[Windows PowerShell] No more events
2016/02/04 14:10:58.107698 winlogbeat.go:227: DBG EventLog[Windows PowerShell] Read() returned 0 records
2016/02/04 14:10:58.135699 client.go:265: DBG ES Ping(url=http://elasticsearch.irisnet.be:80, timeout=1m30s)
2016/02/04 14:10:58.138699 client.go:270: DBG Ping request failed with: 503 Service Unavailable
2016/02/04 14:10:58.138699 single.go:126: INFO Connecting error publishing events (retrying): 503 Service Unavailable
2016/02/04 14:10:58.139700 single.go:152: INFO send fail
2016/02/04 14:10:58.139700 single.go:159: INFO backoff retry: 2s
2016/02/04 14:10:59.105755 wineventlog.go:78: DBG WinEventLog[Application] No more events
2016/02/04 14:10:59.105755 winlogbeat.go:227: DBG EventLog[Application] Read() returned 0 records
2016/02/04 14:10:59.106755 wineventlog.go:78: DBG WinEventLog[Security] No more events
2016/02/04 14:10:59.106755 winlogbeat.go:227: DBG EventLog[Security] Read() returned 0 records
2016/02/04 14:10:59.107755 wineventlog.go:78: DBG WinEventLog[Windows PowerShell] No more events
2016/02/04 14:10:59.107755 winlogbeat.go:227: DBG EventLog[Windows PowerShell] Read() returned 0 records
2016/02/04 14:11:00.106812 wineventlog.go:78: DBG WinEventLog[Security] No more events
2016/02/04 14:11:00.106812 winlogbeat.go:227: DBG EventLog[Security] Read() returned 0 records
2016/02/04 14:11:00.106812 wineventlog.go:78: DBG WinEventLog[Application] No more events
2016/02/04 14:11:00.107812 winlogbeat.go:227: DBG EventLog[Application] Read() returned 0 records
2016/02/04 14:11:00.107812 wineventlog.go:78: DBG WinEventLog[Windows PowerShell] No more events
2016/02/04 14:11:00.108812 winlogbeat.go:227: DBG EventLog[Windows PowerShell] Read() returned 0 records
2016/02/04 14:11:00.139814 client.go:265: DBG ES Ping(url=http://elasticsearch.irisnet.be:80, timeout=1m30s)
2016/02/04 14:11:00.142814 client.go:270: DBG Ping request failed with: 503 Service Unavailable
2016/02/04 14:11:00.142814 single.go:126: INFO Connecting error publishing events (retrying): 503 Service Unavailable
2016/02/04 14:11:00.143814 single.go:152: INFO send fail
2016/02/04 14:11:00.143814 single.go:159: INFO backoff retry: 4s

UnclePhil · February 4, 2016, 2:27pm

and a

curl -X HEAD "http://elasticsearch.irisnet.be:80" from a goog linux client on the same network segment is returning a 200 OK

andrewkroh · February 4, 2016, 4:20pm

How about testing from the Windows host:

PS C:\Users\vagrant> (Invoke-WebRequest -Method Head -Uri http://elasticsearch.irisnet.be:80).statuscode
500

UnclePhil · February 5, 2016, 7:37am

Working perfectly
PS C:\Users\Administrator> (Invoke-WebRequest -Method Head -Uri http://elasticsearch.irisnet.be:80).statuscode
200

andrewkroh · February 6, 2016, 4:55am

All of the beats use the HEAD request to verify that is Elasticsearch is up and running. I'm not seeing anything that could lead to a 503 being returned to the Beat and a 200 being returned to Invoke-WebRequest. Probably the only difference between the requests is the User-Agent header.

Is there anything in between the beat and Elasticsearch (like a reverse proxy)? Is there anything in the logs on the server side indicating the cause of the 503?

Christian_Dahlqvist · February 6, 2016, 6:43am

Do you by any chance have a proxy in front of Elasticsearch that could be causing problems when connecting through port 80?

UnclePhil · February 8, 2016, 2:23pm

Yes we have some proxy in front of the elasticsearch, but when i send data through Powershell from the same machine, i don't have any problem, and the HAproxy doesn't look for any user-agent or something more exotic.
The rule is "everything coming under name elasticsearch.irisnet.be on port 80 is redirected on port 9200"

But this is opening a more deep question;
The transport between beats and elastic is in HTTP, TCP or UDP on port xxxx ? Because the proxy is waiting HTTP with a hostname in the header.
and if it's not http, can i force it and how ???

Best regards

Philippe

Christian_Dahlqvist · February 8, 2016, 2:28pm

The Beats protocol is a custom protocol over TCP, not HTTP.

andrewkroh · February 8, 2016, 2:43pm

For this case the protocol is plain old HTTP. So the proxy expects the Host header to have elasticsearch.irisnet.be then it makes a decision on how to route the request? You could inspect the request from Winlogbeat with Wireshark. I would expect there to be some logging on your proxy to report the reason it is returning a 503.

The Beats output to Logstash is a custom TCP based protocol.

UnclePhil · February 9, 2016, 6:17am

Ok i m going to process some sniffing session.
I let you know.
Many thanks

Philippe

UnclePhil · February 9, 2016, 1:43pm

problem solved, but with a strange origin

when i put the :80 after the hostname , the header coming in the proxy is
hostname:80 when the beat is sending the HEAD and hostname when the beat send the data

And due to the fact that the haproxy was not waiting the hostname:port version we receive the 503.
I change the header processing in the haproxy, and this solve the problem.

Many thanks' for your help

Philippe

andrewkroh · February 9, 2016, 2:31pm

Glad to hear you solved it. I created an enhancement request for the issue you were having. https://github.com/elastic/beats/issues/952