Log warning messages in sensu-server.log from a handler

[kali-brandwatch]

I'm writing custom handlers and often I want to log something so that the information lands in sensu-server.log, as warning or error.

So far the only way I have been able to achieve this, was by breaking the execution of the custom handler with a raise command, which logs the message I want but unconviniently surrounded by the typical ruby stack.

Furthermore this doesn't let me log information while still running the handler code.

Am I doing something wrong or did I simply not manage to set it properly?

I read the documentation and I seem to understand that any output that the handler code prints to stdout will be logged in the sensu-server.log, but this is however not the case.

Any advice would be welcome

[cwjohnston]

Hi @kali-brandwatch, thanks for your question here. I think you can get close to what you're trying to do, but maybe not exactly what you want. Specifically, I don't think you can get multiple lines of output from a single handler execution logged at different levels.

In my experience, handler output is logged at the either the info or error level, with the "handler output" message, depending on the exit status code from the handler plugin.

Here's are some logs from a check result I've sent to this pushover handler plugin via the client local socket:

$ echo '{"name": "handler_output_test",  "status": 2, "output": "testing handler output logging", "handlers": [ "pushover"] }' | nc 127.0.0.1 3030
ok

log output:

$ grep handler_output_test /var/log/sensu/sensu-enterprise.log
{"timestamp":"2018-08-13T20:08:11.515201+0000","level":"info","message":"processing event","event":{"id":"33f311f8-3421-4f07-9fb0-0d296090c10d","client":{"name":"sensu","address":"192.168.11.12","subscriptions":["sensu","debian","client:sensu"],"version":"1.4.1","timestamp":1534190883},"check":{"name":"handler_output_test","status":2,"output":"testing handler output logging","handlers":["pushover"],"executed":1534190891,"issued":1534190891,"type":"standard","history":["2"],"total_state_change":0},"occurrences":1,"occurrences_watermark":1,"last_ok":null,"action":"create","timestamp":1534190891,"last_state_change":1534190891,"silenced":false,"silenced_by":[]}}

{"timestamp":"2018-08-13T20:08:12.108271+0000","level":"info","message":"handler output","handler":{"type":"pipe","command":"handler-pushover.rb","filters":["occurrences"],"name":"pushover"},"event":{"id":"33f311f8-3421-4f07-9fb0-0d296090c10d"},"output":["pushover -- sent alert for sensu/handler_output_tes to user: REDACTED, token: REDACTED.\n"]}

As you can hopefully see in the last log line above, the output of the handler plugin is reflected in the value of theoutput key.

Usingexit in your handler with a non-0 value will cause the log level to be error instead of info,

Regardless of the exit status, Sensu will log all handler output in the same message once handler execution has finished. This means that you can output as many messages as you like to STDOUT/STDERR and then exit with the applicable status code to influence log level.

[kali-brandwatch]

I think I never got notified of this reply. This actually worked for me. I managed to see in the sensu-server log the errors i want by using exit N where N<>0 without needing to set the log level to info. Before I was only able to see it by using raise in the handlers, which would include the full stack trace which is rather ugly for the logs. Thanks a lot.