UDP input TCP output and Gelf

[Hermain]

Can I use this to receive Gelf udp packages (gelf is a subset of Json) and forward them to logstash with TCP? I don't want to run logstash on every machine in my cluster and am looking for a lightweight solution to forward the UDP log messages (docker gelf logging driver only supports udp) to logstash reliably (logstash)

[hartfordfive]

@Hermain From what I know of the GELF format, the resulting messages can be chunked and/or compressed. Consequently, this beat doesn't directly support the format as there's no logic to handle reassembling potentially larger messages via UDP that span multiple chunks nor is there any decompressions. It only accepts plain uncompressed text/json as input.

In theory, you could adapt this beat to implement a support for the GELF message with Graylog's GELF reader. As for the output, you could then just implement the logstash output and then apply any final processing there.

[Hermain]

I think I'll just wait until docker supports Gelf logging over TCP and use some other solution until then or accept that I might loose some log messages. Thank you

[hartfordfive]

@Hermain Let me take a look at the specifications and the Go code for the GELF format and if it doesn't diverge much from the purpose of this beat, then I see no harm in implementing and additional option to support GELF message format as input.

[Hermain]

That would be great. Thank you for considering it. https://blog.docker.com/2017/02/adventures-in-gelf/ This link discribes the kind of issues that you have with the docker gelf driver and there is no good solution for this except for running logstash on each machine. I looked for a good solution for a long time and found nothing. The Gelf driver has a lot of additional fields it adds to each docker log message which no other driver delivers so theres added value

[hartfordfive]

@Hermain Seems like this was relatively simply to implement with Graylog's Go library. I'm just doing a few things to test so I should have a new version with GELF input support within the next day or so. Seeing I don't really work with Graylog, I'll probably ask you (if you don't mind) to do a bit of testing on your side with some data before I release the next version. Let me know if that's ok with you.

[Hermain]

@hartfordfive I would gladly try to use this beat with logstash and the gelf plugin.

[hartfordfive]

@Hermain I've got a beta build up if you'd like to test it:

https://github.com/hartfordfive/protologbeat/releases/tag/0.2.0-beta

You'll have to set the following config:

protologbeat.enable_gelf: true

I've done some minimal testing on my side and it seems to work fine with small basic messages. Let me know how it works with more realistic message payloads. So if you're shipping data to Logstash, your config might look something like this:

protologbeat:
  address: "127.0.0.1"
  port: 12201
  default_es_log_type: graylog
  merge_fields_to_root: true
  enable_gelf: true

output.logstash:
  # The Logstash hosts
  hosts: ["yourlogstashhost.com:5044"]

  # List of root certificates for HTTPS server verifications
  ssl.certificate_authorities: ["/etc/pki/root/ca.pem"]

  # Certificate for SSL client authentication
  ssl.certificate: "/etc/pki/client/cert.pem"

  # Client Certificate Key
  ssl.key: "/etc/pki/client/cert.key"

You can set default_es_log_type to which ever value you'd like. Just keep in mind that when protologbeat is in GELF mode, it will only accept messages in GELF format. If you want to be able to log messages in a different format, such as plaintext or JSON, then you'll have to run separate instance with the necessary config.

[Hermain]

I added it to my current sprint and will have a look at it after the current ticket I am working on.
Am I right that Logstash would require an input configuration like this?

input {
  beats {
    port => 5044
  }
}

[hartfordfive]

Similar, but you'll need to add your ssl parameters:

input {
  beats {
    port => 5044
    ssl => true
    ssl_certificate_authorities => ["/etc/ca.crt"]
    ssl_certificate => "/etc/server.crt"
    ssl_key => "/etc/server.key"
    ssl_verify_mode => "force_peer"
  }
}

For more info about securing your filbeat/logstash connection, you can view this documentation page.

[Hermain]

@hartfordfive I tested protologbeat without encryption and it didn't work. Logstash received messages but the output was all scrambled.
I don't need encryption because my containers are in an overlay network and docker takes care of encryption of messages.

I containerized the binary you sent me with the follwing dockerfile:

COPY protologbeat-0.2.0-beta-linux-x86_64 /protologbeat
COPY conf.yml /conf.yml

CMD ["/protologbeat", "-c", "/conf.yml", "-e", "-d", "\"*\""]

using config.yml:

  address: "0.0.0.0"
  port: 12201
  default_es_log_type: graylog
  merge_fields_to_root: true
  enable_gelf: true

output.logstash:
  # The Logstash hosts
  hosts: ["logstash:5044"]

and generated the logmessages with:

docker run --log-driver=gelf --log-opt gelf-address=udp://127.0.0.1:12201 ubuntu /bin/sh -c 'while true; do date "+%d-%m-%Y %H:%M:%S:%3N" | xargs printf "%s %s | 51c489da-2ba7-466e-abe1-14c236de54c5 | INFO | HostingLoggerExtensions.RequestFinished    | Request finished in 35.1624ms 200 application/json; charset=utf-8 message end\n"; sleep 1 ; done'

Here the part of the docker-compose file which describes logstash:

  logstash:
    image: docker.elastic.co/logstash/logstash:5.3.1
    logging:
      driver: "json-file"
    networks:
      - logging
    entrypoint: logstash -e 'input { beats { port => 5044 } } output { stdout{ } elasticsearch { hosts => ["http://elasticsearch:9200"] } }'

Protologbeat log Output:

2017/05/19 13:32:54.295486 beat.go:267: INFO Home path: [/] Config path: [/] Data path: [//data] Logs path: [//logs]
2017/05/19 13:32:54.295511 beat.go:177: INFO Setup Beat: protologbeat; Version: 5.2.3
2017/05/19 13:32:54.295557 logstash.go:90: INFO Max Retries set to: 3
2017/05/19 13:32:54.298221 outputs.go:106: INFO Activated logstash as output plugin.
2017/05/19 13:32:54.298289 publish.go:291: INFO Publisher name: 18211f854301
2017/05/19 13:32:54.298507 async.go:63: INFO Flush Interval set to: 1s
2017/05/19 13:32:54.298514 async.go:64: INFO Max Bulk Size set to: 2048
2017/05/19 13:32:54.305548 beat.go:207: INFO protologbeat start running.
2017/05/19 13:32:54.305568 protologbeat.go:39: INFO protologbeat is running! Hit CTRL-C to stop it.
2017/05/19 13:32:54.305745 loglistener.go:101: INFO Now listening for logs via udp on 0.0.0.0:12201
2017/05/19 13:32:54.305817 logp.go:219: INFO Metrics logging every 30s
2017/05/19 13:33:24.308395 logp.go:232: INFO No non-zero metrics in the last 30s
2017/05/19 13:33:54.307153 logp.go:232: INFO No non-zero metrics in the last 30s
2017/05/19 13:34:24.306329 logp.go:232: INFO No non-zero metrics in the last 30s
2017/05/19 13:34:54.306152 logp.go:232: INFO No non-zero metrics in the last 30s
2017/05/19 13:35:24.306108 logp.go:232: INFO No non-zero metrics in the last 30s
2017/05/19 13:35:49.288239 protologbeat.go:66: INFO Event sent
2017/05/19 13:35:50.291791 protologbeat.go:66: INFO Event sent
2017/05/19 13:35:51.298255 protologbeat.go:66: INFO Event sent
2017/05/19 13:35:52.307655 protologbeat.go:66: INFO Event sent
2017/05/19 13:35:53.310859 protologbeat.go:66: INFO Event sent
.
.
.
.

Logstash received:
2017-05-19T13:35:55.330Z 18211f854301 ��n���̒�j�6��_� �U��I�dɡ7������Rh����c[�X�Xr���w_&���>����/��
�9.�uL�۱iɅul�u���k������v,O�Z�3��#�� Ws]K.Z�M��N뮑-@
��
X���Z�C5�$j��lL ���
��x��\�a�%���e�i���P�qIy�D���r�S���
<��F���S��� ���F�9����|>E�%.��C^��� �L嗭
���rƑ�R;V�L��|f��+�%�N�FZ��n�N�B'֙�;�e�1ֱ�>��<A��u�'��nta�����n�PWs]��CW��UwU�xp�7\�
�5�2��U��
���+��ֲǶV�P��O��������
������;�%����c
�cR �i=�je�R���������E͛�o���j9��}��F/����ɾ�L8_�#�i=��)�bδ������-�h�@
��x�Q�}�Tc������8�H_�� �6ݠ����pAVYťAK��=q��V7�sR�D�+�]k�0����o�_#n���v=��؁}����p��im�

[hartfordfive]

I've tested with the basic GELF message writer function that comes with the Go GELF library and I've also tested by sending raw messages like this:

echo '{"version": "1.1","host":"example.org","short_message":"A short message that helps you identify what is going on","full_message":"Ba_user_id":9001,"_some_info":"foo","_some_env_var":"bar"}' | gzip | nc -u -w 1 127.0.0.1 12201

Both of these cases work fine as I can see the resulting data in Elasticsearch in the proper self format. I'm digging a bit deeper to see what the issue might be here. Which version of Logstash are you using?

[Hermain]

I'm using logstash:5.3.1. I would try to have a docker container generate gelf messages as this is how I got the scramled results (which also show in kibana)

All you need is to have docker installed.

docker run --log-driver=gelf --log-opt gelf-address=udp://127.0.0.1:12201 ubuntu /bin/sh -c 'while true; do date "+%d-%m-%Y %H:%M:%S:%3N" | xargs printf "%s %s | 51c489da-2ba7-466e-abe1-14c236de54c5 | INFO | HostingLoggerExtensions.RequestFinished    | Request finished in 35.1624ms 200 application/json; charset=utf-8 message end\n"; sleep 1 ; done'

Thank you very much for your work

[Hermain]

I remembered that docker does some compression and tried gelf-compression-type=none. This fixed the issue and Logstash receives proper entries. The standart compression type of docker Gelf messages is Gzip. The logstash gelf plugin worked with gzip compressed messages. Was it intended for protologbeat to support compressed data (maybe the code from the gelf logstash plugin can be used)?

docker run --log-driver=gelf --log-opt gelf-address=udp://127.0.0.1:12201 --log-opt gelf-compression-type=no ubuntu /bin/sh -c 'while true; do echo "hello"; sleep 1 ; done

[hartfordfive]

Sorry for the delay. I just checked the documentation for docker and you're right. It does in fact say the default compression is GZIP for GELF messages. The detection of compression type should be automatic determined with the magic byte header, as shown here in the Graylog package Read function. I'm not sure why it wasn't automatically detecting the compression, although I wouldn't really advise on using compression in this case as protologbeat should be local to your docker instance. There's no network transmission from the docker GELF logging driver to the protologbeat beat instance in this case, so you'll just be using up additional CPU to compress/decompress the data.

[Hermain]

@hartfordfive I guess for my specific usecase it might not be a big problem but it should nevertheless work. I will now test this on my development swarm without compression and see if I encounter further issues.

[Hermain]

The entire gelf message goes into the message field.
The nice thing about gelf is that everything is nicely split up into multiple fields.
Should I use logstash (maybe with json plugin) to try to split the gelf entries or would it make sense to do this in protologbeat? https://github.com/logstash-plugins/logstash-input-gelf/blob/master/lib/logstash/inputs/gelf.rb this is how the gelf plugin does it

[hartfordfive]

Can you send me an example of the final document that gets indexed in Elasticsearch?

[Hermain]

This is an example:

{
  "_index": "logstash-2017.05.24",
  "_type": "graylog",
  "_id": "AVw6jmxM_cY-SZ_YANcW",
  "_score": null,
  "_source": {
    "@timestamp": "2017-05-24T13:03:49.939Z",
    "@version": "1",
    "beat": {
      "hostname": "18211f854301",
      "name": "18211f854301",
      "version": "5.2.3"
    },
    "host": "18211f854301",
    "message": "{\"version\":\"1.1\",\"host\":\"herm-VirtualBox\",\"short_message\":\"24-05-2017 13:03:49:937 | 51c489da-2ba7-466e-abe1-14c236de54c5 | INFO | HostingLoggerExtensions.RequestFinished    | Request finished in 35.1624ms 200 application/json; charset=utf-8 message end\",\"timestamp\":1.495631029938e+09,\"level\":6,\"_command\":\"/bin/sh -c while true; do date \\\"+%d-%m-%Y %H:%M:%S:%3N\\\" | xargs printf \\\"%s %s | 51c489da-2ba7-466e-abe1-14c236de54c5 | INFO | HostingLoggerExtensions.RequestFinished    | Request finished in 35.1624ms 200 application/json; charset=utf-8 message end\\\\n\\\"; sleep 1 ; done\\n\",\"_container_id\":\"78a95d70c9ee677d8acaeed0e0ba0e3dafb704a7e41f1b4048421686a26a695c\",\"_container_name\":\"admiring_goodall\",\"_created\":\"2017-05-24T13:03:49.679248374Z\",\"_image_id\":\"sha256:f49eec89601e8484026a8ed97be00f14db75339925fad17b440976cffcbfb88a\",\"_image_name\":\"ubuntu\",\"_tag\":\"78a95d70c9ee\"}",
    "type": "graylog",
    "tags": [
      "beats_input_codec_plain_applied",
      "_grokparsefailure"
    ]
  },
  "fields": {
    "@timestamp": [
      1495631029939
    ]
  },
  "sort": [
    1495631029939
  ]
}

Right now I try to use the json filter to split the fields up but then I get issues because the docker fields start with '_'

[hartfordfive]

Ahh, yes you simply have to use the logstash JSON plugin. That will parse all the data and merge it to the root level. For example, add this into your filter stage:

json {
   source => "message"
   tag_on_failure => ["_gelf_parse_failure"]
}

The tag_on_failure options isn't necessary, although in the case where there's an error I find it nice to have a specific tag on my messages that makes it clear where the error came from.

[Hermain]

I did some testing:
First the positive :) The CPU/RAM usage seems very reasonable
Now the negative:
I created a container that creates logentries with a whole bunch of fields and one of those fields is a increasing counter. This container spams messages (not very quick because of the date command) using the gelf log:

docker run --log-driver=gelf --log-opt gelf-address=udp://127.0.0.1:12201 --log-opt gelf-compression-type=none ubuntu /bin/sh -c 'COUNTER=1;while true; do date "+%d-%m-%Y %H:%M:%S:%3N" SOME LONG STRING IN MY LOG FORMAT | $COUNTER\n"; COUNTER=$((COUNTER+1)); sleep 1; done'

Now I have seen the following issues:

• Some logentries are received twice and the one logentry before is lost (I received 1031 twice 1030 never)
• Sometimes one logentry is lost, the next one is sent twice but one of them has a _gelf_parse_failure (I used the json filter as you suggested) because the message is not proper json because the json is never closed:

{"version":"1.1","host":"herm-VirtualBox","short_message":"29-05-2017 14:56:17:533 | 51c489da-2ba7-466e-abe1-14c236de54c5 | INFO | HostingLoggerExtensions.RequestFinished | 1048","timestamp":1.496069777534e+09,"level":6,"_command":"/bin/sh -c COUNTER=1;while true; do date \"+%d-%m-%Y %H:%M:%S:%3N\" | xargs printf \"%s %s | 51c489da-2ba7-466e-abe1-14c236de54c5 | INFO | HostingLoggerExtensions.RequestFinished | $COUNTER\\n\"; COUNTER=$((COUNTER+1)); done","_container_id":"7b89f1b56ba6f773896969100fca6466a30cdfefe15cf06243df63b66ea3c46d","_container_name":"pensive_northcutt","_created":"2017-05-29T14:56:08.48203809Z","_image_id":"sha256:f49eec89601e8484026a8ed97be00f14db75339925fad17b440976cffcbfb88a","_image_name":"ubuntu","_tag":"7b89f1b56ba6"

Any idea what this could be? It happens quite frequently.
If we get this to run properly I will write a documentation page about it on stackoverflow since I've seen a lot of people having problem with delivering gelf docker logs.

[hartfordfive]

@Hermain I apologize for the delayed response. I'll try to take some time by the end of the week to look at this a bit further.

[Hermain]

I will be on holiday from the 17.6 until 16.7 so I won't be able to test any changes or answer any questions then. This does not mean I'm not interested :)

[hartfordfive]

Thanks for the heads up and I apologize for not having the time to look into your issues sooner. Hoping to be able to get back to my OS projects soon!

…

On Mon, Jun 12, 2017 at 5:12 AM Hermain ***@***.***> wrote: I will be on holiday from the 17.6 until 16.7 so I won't be able to test any changes or answer any questions then. This does not mean I'm not interested :) — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#3 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/ADjN8M2ljZjZJgMzpc6ZNIDCmfmjoGjmks5sDQEPgaJpZM4NUHr1> .

[hartfordfive]

@Hermain Sorry I haven't been able to get around to this yet. Between vacations and a very busy few months with my actual day job, I haven't been able to look at this yet although I haven't forgotten.

[Hermain]

@hartfordfive If I read the release notes for Version 0.2.0 it sound like some of the issues might have been fixed. Is that true?

[hartfordfive]

@Hermain I haven't actually had the chance to get around to checking out some of your issues unfortunately. I have another fix that was released so I figured I'd include the GELF input feature although that's still in beta.