Winlogbeats not working with SSL configuration to Logstash

patricktula · April 3, 2018, 5:12am

Hi,

I need some assistance with my Winlogbeats SSL configuration.

My winlogbeats machine sending logs yml config:

winlogbeat.event_logs:
  - name: Application
    ignore_older: 72h
  - name: Security
  - name: System

setup.template.settings:

fields:
  client:
      clientName
setup.kibana:

output.logstash:
  # The Logstash hosts
 hosts: ["192.168.100.244:5044"]
  ssl.certificate_authorities: ["c:/programdata/winlogbeat/ca.crt"]
  ssl.certificate: "c:/programdata/winlogbeat/client.crt"
  ssl.key: "c:/programdata/winlogbeat/client.key"

logging.level: info
logging.level: debug
logging.level: error
logging.level: warning

logging.selectors: ["*"]

My Logstash server:

input {
  beats {
    port => 5044
    type => "logs"
    ssl => true
    ssl_certificate => "C:/temp/WinlogBeatsSSL/client.crt"
    ssl_key => "C:/temp/WinlogBeatsSSL/client.key"
  }
}

output {
  elasticsearch {
    hosts => "localhost:9200"
    manage_template => false
    index => "%{[@metadata][beat]}-%{+YYYY.MM.dd}"
    document_type => "%{[@metadata][type]}"
  }
}

I am not getting any logs once I enable SSL, but once disabled, it works fine.

Please advise what I am doing wrong.

thanks,
Pat

andrewkroh · April 3, 2018, 1:55pm

What does the command tell you?

PS C:\Program Files\Winlogbeat> .\winlogbeat.exe test output -e -d "*"

patricktula · April 3, 2018, 2:40pm

H:\WinlogBeats>.\winlogbeat.exe test output -e -d "*"
2018-04-03T07:36:18.424-0700    INFO    instance/beat.go:468    Home path: [H:\W
inlogBeats] Config path: [H:\WinlogBeats] Data path: [H:\WinlogBeats\data] Logs
path: [H:\WinlogBeats\logs]
2018-04-03T07:36:18.430-0700    DEBUG   [beat]  instance/beat.go:495    Beat met
adata path: H:\WinlogBeats\data\meta.json
2018-04-03T07:36:18.434-0700    INFO    instance/beat.go:475    Beat UUID: 4afcb
bd1-4864-42d1-ad55-1e9939740496
Error initializing output: missing required field accessing 'output.logstash.hos
ts'

patricktula · April 3, 2018, 2:42pm

Just a little pre-note, this works just fine if I do not have ssl enabled, but we do not want that.

I think I may not have my certs in order. I will try and re-create some and redeploy and let you know.

andrewkroh · April 3, 2018, 3:00pm

patricktula:

output.logstash:
  # The Logstash hosts
 hosts: ["192.168.100.244:5044"]
  ssl.certificate_authorities: ["c:/programdata/winlogbeat/ca.crt"]
  ssl.certificate: "c:/programdata/winlogbeat/client.crt"
  ssl.key: "c:/programdata/winlogbeat/client.key"

The indentation is wrong in your configuration. It should look like:

output.logstash:
  # The Logstash hosts
  hosts: ["192.168.100.244:5044"]
  ssl.certificate_authorities: ["c:/programdata/winlogbeat/ca.crt"]
  ssl.certificate: "c:/programdata/winlogbeat/client.crt"
  ssl.key: "c:/programdata/winlogbeat/client.key"

patricktula · April 3, 2018, 6:35pm

Thanks Andrew. I updated it, and now getting this error below
H:\WinlogBeats>.\winlogbeat.exe -c winlogbeat.yml -e -d "*" -configtest
Flag --configtest has been deprecated, configtest flag has been deprecated, use
test config subcommand
2018-04-03T11:30:25.901-0700 INFO instance/beat.go:468 Home path: [H:\W
inlogBeats] Config path: [H:\WinlogBeats] Data path: [H:\WinlogBeats\data] Logs
path: [H:\WinlogBeats\logs]
2018-04-03T11:30:25.903-0700 DEBUG [beat] instance/beat.go:495 Beat met
adata path: H:\WinlogBeats\data\meta.json
2018-04-03T11:30:25.904-0700 INFO instance/beat.go:475 Beat UUID: 4afcb
bd1-4864-42d1-ad55-1e9939740496
2018-04-03T11:30:25.905-0700 INFO instance/beat.go:213 Setup Beat: winl
ogbeat; Version: 6.2.3
2018-04-03T11:30:25.909-0700 WARN instance/metrics_other.go:8 Metrics
not implemented for this OS.
2018-04-03T11:30:25.911-0700 DEBUG [beat] instance/beat.go:230 Initiali
zing output plugins
2018-04-03T11:30:25.912-0700 DEBUG [processors] processors/processor.go:
49 Processors:
2018-04-03T11:30:25.914-0700 ERROR outputs/tls.go:229 Dropping encrypt
ed pem 'RSA PRIVATE KEY' block read from c:/programdata/winlogbeat/client.key. N
o passphrase available
2018-04-03T11:30:25.917-0700 ERROR outputs/tls.go:184 Failed reading k
ey file c:/programdata/winlogbeat/client.key: no PEM blocks
2018-04-03T11:30:25.920-0700 ERROR instance/beat.go:667 Exiting: error i
nitializing publisher: 1 error: no PEM blocks c:/programdata/winlogbeat/client.k
ey
Exiting: error initializing publisher: 1 error: no PEM blocks c:/programdata/win
logbeat/client.key

andrewkroh · April 3, 2018, 7:04pm

The client certificate that you have configured Winlogbeat to use to authenticate to Logstash appears to be encrypted. Winlogbeat must be configured with the decryption password in order to use this client certificate. Use ssl.key_passphrase for this.

patricktula · April 3, 2018, 7:27pm

That got the service started up!

I checked again and do not see any more errors, but still yet to see logs on Kibana as I was seeing before I enabled SSL.

H:\WinlogBeats>.\winlogbeat.exe -c winlogbeat.yml -e -d "*" -configtest
Flag --configtest has been deprecated, configtest flag has been deprecated, use
test config subcommand
2018-04-03T12:20:07.186-0700    INFO    instance/beat.go:468    Home path: [H:\W
inlogBeats] Config path: [H:\WinlogBeats] Data path: [H:\WinlogBeats\data] Logs
path: [H:\WinlogBeats\logs]
2018-04-03T12:20:07.191-0700    DEBUG   [beat]  instance/beat.go:495    Beat met
adata path: H:\WinlogBeats\data\meta.json
2018-04-03T12:20:07.195-0700    INFO    instance/beat.go:475    Beat UUID: 4afcb
bd1-4864-42d1-ad55-1e9939740496
2018-04-03T12:20:07.198-0700    INFO    instance/beat.go:213    Setup Beat: winl
ogbeat; Version: 6.2.3
2018-04-03T12:20:07.201-0700    WARN    instance/metrics_other.go:8     Metrics
not implemented for this OS.
2018-04-03T12:20:07.204-0700    DEBUG   [beat]  instance/beat.go:230    Initiali
zing output plugins
2018-04-03T12:20:07.207-0700    DEBUG   [processors]    processors/processor.go:
49      Processors:
2018-04-03T12:20:07.216-0700    INFO    pipeline/module.go:76   Beat name: SQLPR
ODUCTION
2018-04-03T12:20:07.218-0700    INFO    beater/winlogbeat.go:56 State will be re
ad from and persisted to H:\WinlogBeats\data\.winlogbeat.yml
2018-04-03T12:20:07.221-0700    DEBUG   [eventlog]      eventlog/factory.go:129
Using highest priority API, wineventlog, for event log Application
2018-04-03T12:20:07.226-0700    DEBUG   [winlogbeat]    beater/winlogbeat.go:83
Initialized EventLog[Application]
2018-04-03T12:20:07.229-0700    DEBUG   [processors]    processors/processor.go:
49      Processors:
2018-04-03T12:20:07.232-0700    DEBUG   [eventlog]      eventlog/factory.go:129
Using highest priority API, wineventlog, for event log Security
2018-04-03T12:20:07.236-0700    DEBUG   [winlogbeat]    beater/winlogbeat.go:83
Initialized EventLog[Security]
2018-04-03T12:20:07.239-0700    DEBUG   [processors]    processors/processor.go:
49      Processors:
2018-04-03T12:20:07.241-0700    DEBUG   [eventlog]      eventlog/factory.go:129
Using highest priority API, wineventlog, for event log System
2018-04-03T12:20:07.245-0700    DEBUG   [winlogbeat]    beater/winlogbeat.go:83
Initialized EventLog[System]
2018-04-03T12:20:07.248-0700    DEBUG   [processors]    processors/processor.go:
49      Processors:
2018-04-03T12:20:07.251-0700    WARN    [cfgwarn]       instance/beat.go:283
DEPRECATED: -configtest flag has been deprecated, use configtest subcommand Will
 be removed in version: 6.0
Config OK
2018-04-03T12:20:07.251-0700    INFO    [monitoring]    log/log.go:97   Starting
 metrics logging every 30s
2018-04-03T12:20:07.260-0700    INFO    [monitoring]    log/log.go:132  Total no
n-zero metrics  {"monitoring": {"metrics": {"libbeat":{"config":{"module":{"runn
ing":0}},"output":{"type":"logstash"},"pipeline":{"clients":0,"events":{"active"
:0}}},"uptime":"{\"server_time\":\"2018-04-03T19:20:07.2608827Z\",\"start_time\"
:\"2018-04-03T19:20:07.1688735Z\",\"uptime\":\"92.0092ms\",\"uptime_ms\":\"92009
\"}"}}}
2018-04-03T12:20:07.269-0700    INFO    [monitoring]    log/log.go:133  Uptime:
155.6081ms
2018-04-03T12:20:07.272-0700    INFO    [monitoring]    log/log.go:110  Stopping
 metrics logging.

Kibana logs stuck on April 2, 2018 - image below

andrewkroh · April 3, 2018, 7:52pm

Have you started the Beat since then (without -configtest)? Run Winlogbeat for a few minutes and post the logs. If you want it to resend all data you can delete the registry file at C:\ProgramData\winlogbeat\.winlogbea.tyml before starting Winlogbeat

Your Logstash config doesn't match up with the recommendations in the Beats documentation. See Setup Logstash. And you must load the index template into Elasticsearch manually because the options for auto loading the template are only available for the Elasticsearch output.

And setting type => "logs" doesn't do anything because the value is already set by Winlogbeat. See type in the Logstash beats input docs for the details.

patricktula · April 3, 2018, 9:12pm

Ran without -configtest and it looks like showing all the event logs.

2018-04-03T14:03:53.584-0700 DEBUG [winlogbeat] beater/eventlogger.go:11
6 EventLog[Application] Read() returned 0 records
2018-04-03T14:03:54.588-0700 DEBUG [eventlog_detail] eventlog/wineven
tlog.go:180 WinEventLog[Application] No more events
2018-04-03T14:03:54.588-0700 DEBUG [winlogbeat] beater/eventlogger.go:11
6 EventLog[Application] Read() returned 0 records
2018-04-03T14:03:55.591-0700 DEBUG [eventlog_detail] eventlog/wineven
tlog.go:180 WinEventLog[Application] No more events
2018-04-03T14:03:55.591-0700 DEBUG [winlogbeat] beater/eventlogger.go:11
6 EventLog[Application] Read() returned 0 records
2018-04-03T14:03:56.594-0700 DEBUG [eventlog_detail] eventlog/wineven
tlog.go:180 WinEventLog[Application] No more events
2018-04-03T14:03:56.594-0700 DEBUG [winlogbeat] beater/eventlogger.go:11
6 EventLog[Application] Read() returned 0 records
2018-04-03T14:03:57.598-0700 DEBUG [eventlog_detail] eventlog/wineven
tlog.go:180 WinEventLog[Application] No more events
2018-04-03T14:03:57.598-0700 DEBUG [winlogbeat] beater/eventlogger.go:11
6 EventLog[Application] Read() returned 0 records
2018-04-03T14:03:57.770-0700 DEBUG [service] service/service.go:33
Received sigterm/sigint, stopping
2018-04-03T14:03:57.770-0700 INFO beater/winlogbeat.go:152 Stopping
Winlogbeat
2018-04-03T14:03:57.770-0700 DEBUG [service] service/service.go:39
Received svc stop/shutdown request
2018-04-03T14:03:57.770-0700 INFO beater/eventlogger.go:92 EventLog
[System] Stop processing.
2018-04-03T14:03:57.771-0700 DEBUG [eventlog] eventlog/wineventlog.go:
166 WinEventLog[System] Closing handle
2018-04-03T14:03:57.771-0700 INFO beater/eventlogger.go:92 EventLog
[Security] Stop processing.
2018-04-03T14:03:57.771-0700 DEBUG [eventlog] eventlog/wineventlog.go:
166 WinEventLog[Security] Closing handle
2018-04-03T14:03:58.602-0700 INFO beater/eventlogger.go:92 EventLog
[Application] Stop processing.
2018-04-03T14:03:58.602-0700 DEBUG [eventlog] eventlog/wineventlog.go:
166 WinEventLog[Application] Closing handle
2018-04-03T14:03:58.602-0700 INFO instance/beat.go:308 winlogbeat stopp
ed.
2018-04-03T14:03:58.602-0700 INFO [monitoring] log/log.go:132 Total no
n-zero metrics {"monitoring": {"metrics": {"libbeat":{"config":{"module":{"runn
ing":0}},"output":{"read":{"errors":2},"type":"logstash","write":{"bytes":276}},
"pipeline":{"clients":0,"events":{"active":4116,"failed":147,"published":4116,"r
etry":2705,"total":4263}}},"msg_file_cache":{"ApplicationHits":154,"ApplicationM
isses":10,"SecurityHits":1899,"SecurityMisses":1,"SystemHits":2166,"SystemMisses
":34},"uptime":"{"server_time":"2018-04-03T21:03:58.6025239Z","start_time"
:"2018-04-03T21:01:14.082329Z","uptime":"2m44.5201949s","uptime_ms":"16
4520194"}"}}}
2018-04-03T14:03:58.603-0700 INFO [monitoring] log/log.go:133 Uptime:
2m44.5430028s

From c:\winlogbeat\programdata\logs\winlogbeat

2018-04-03T14:01:13.563-0700	ERROR	pipeline/output.go:74	Failed to connect: dial tcp 192.168.100.244:5044: connectex: No connection could be made because the target machine actively refused it.
2018-04-03T14:01:22.544-0700	ERROR	pipeline/output.go:74	Failed to connect: dial tcp 192.168.100.244:5044: connectex: No connection could be made because the target machine actively refused it.
2018-04-03T14:01:39.548-0700	ERROR	pipeline/output.go:74	Failed to connect: dial tcp 192.168.100.244:5044: connectex: No connection could be made because the target machine actively refused it.
2018-04-03T14:02:12.549-0700	ERROR	pipeline/output.go:74	Failed to connect: dial tcp 192.168.100.244:5044: connectex: No connection could be made because the target machine actively refused it.
2018-04-03T14:03:13.582-0700	ERROR	pipeline/output.go:74	Failed to connect: dial tcp 192.168.100.244:5044: connectex: No connection could be made because the target machine actively refused it.
2018-04-03T14:04:13.603-0700	ERROR	pipeline/output.go:74	Failed to connect: read tcp 192.168.100.213:55488->192.168.100.244:5044: wsarecv: An existing connection was forcibly closed by the remote host.
2018-04-03T14:05:13.591-0700	ERROR	pipeline/output.go:74	Failed to connect: read tcp 192.168.100.213:55549->192.168.100.244:5044: wsarecv: An existing connection was forcibly closed by the remote host.

I have updated logstash setup to now look like this

input {
beats {
port => 5044
ssl => true
ssl_certificate => "C:/temp/WinlogBeatsSSL/Certificates/server.crt"
ssl_key => "C:/temp/WinlogBeatsSSL/Keys/server.key"

}
}

output {
elasticsearch {
hosts => "localhost:9200"
manage_template => false
index => "%{[@metadata][beat]}-%{[@metadata][version]}-%{+YYYY.MM.dd}"
document_type => "%{[@metadata][type]}"
}
}

And have loaded the template manually on the Winlogbeats computer to the elasticsearch server

Still no logs. Stuck at the same time and date

andrewkroh · April 3, 2018, 9:34pm

I don't think you have shared the output from this yet:

patricktula · April 3, 2018, 9:47pm

here you go:

H:\WinlogBeats> .\winlogbeat.exe test output -e -d "*"
2018-04-03T14:42:54.318-0700 INFO instance/beat.go:468 Home path: [H:\W
inlogBeats] Config path: [H:\WinlogBeats] Data path: [H:\WinlogBeats\data] Logs
path: [H:\WinlogBeats\logs]
2018-04-03T14:42:54.324-0700 DEBUG [beat] instance/beat.go:495 Beat met
adata path: H:\WinlogBeats\data\meta.json
2018-04-03T14:42:54.328-0700 INFO instance/beat.go:475 Beat UUID: 4afcb
bd1-4864-42d1-ad55-1e9939740496
logstash: 192.168.100.244:5044...
connection...
parse host... OK
dns lookup... OK
addresses: 192.168.100.244
dial up... OK
TLS...
security: server's certificate chain verification is enabled
handshake... ERROR write tcp 192.168.100.213:57847->192.168.100.244:5044: ws
asend: An existing connection was forcibly closed by the remote host.

patricktula · April 3, 2018, 9:48pm

Logstash config:

input {
beats {
port => 5044
ssl => true
ssl_certificate_authorities => ["C:/temp/WinlogBeatsSSL/Certificates/RootCA.crt"]
ssl_certificate => "C:/temp/WinlogBeatsSSL/Certificates/server.crt"
ssl_key => "C:/temp/WinlogBeatsSSL/Keys/server.key"
ssl_verify_mode => "force_peer"
}
}

output {
elasticsearch {
hosts => "localhost:9200"
manage_template => false
index => "%{[@metadata][beat]}-%{[@metadata][version]}-%{+YYYY.MM.dd}"
document_type => "%{[@metadata][type]}"
}
}

andrewkroh · April 3, 2018, 10:04pm

The above Logstash config looks good. Is this what was running when you ran the winlogbeat test output command?

It seems like Logstash is rejecting the client certificate. Though I think to confirm that you will need to look at the logs on the server side (Logstash). Is the client certificate signed by what's in C:/temp/WinlogBeatsSSL/Certificates/RootCA.crt? Are there any details in the Logstash log output?

patricktula · April 3, 2018, 11:08pm

Ok had to re-create my certs again because was seeing 'bad key' on logstash errors, and got no more errors running .\winlogbeat.exe test output -e -d "*"

H:\WinlogBeats> .\winlogbeat.exe test output -e -d "*"
2018-04-03T16:00:34.805-0700 INFO instance/beat.go:468 Home path: [H:\W
inlogBeats] Config path: [H:\WinlogBeats] Data path: [H:\WinlogBeats\data] Logs
path: [H:\WinlogBeats\logs]
2018-04-03T16:00:34.810-0700 DEBUG [beat] instance/beat.go:495 Beat met
adata path: H:\WinlogBeats\data\meta.json
2018-04-03T16:00:34.813-0700 INFO instance/beat.go:475 Beat UUID: 4afcb
bd1-4864-42d1-ad55-1e9939740496
logstash: corputility001w:5044...
connection...
parse host... OK
dns lookup... OK
addresses: 192.168.100.244, 192.168.100.245
dial up... OK
TLS...
security: server's certificate chain verification is enabled
handshake... OK
TLS version: TLSv1.2
dial up... OK
talk to server... OK

Still not seeing any logs though unfortunately.

On Logstash Logs seeing this error now:

Caused by: javax.net.ssl.SSLHandshakeException: error:100000f7:SSL routines:OPENSSL_internal:WRONG_VERSION_NUMBER

andrewkroh · April 4, 2018, 12:19am

You could try deleting the registry file to see if it then resends all data.

Do you have more than this one client sending data to Logstash? Is there any other client that could be misconfigured. The exception should an IP and port associated with the client.

patricktula · April 4, 2018, 3:59am

It's working! Awesome support here Mr. Kroh. Thank you very much. Have a great night sir!

patricktula · April 4, 2018, 3:59am

BTW: Got Filebeats working as well with SSL using same format!

system · May 2, 2018, 4:00am

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