Parsing Chef's Multiline Output

Hello,

I would like to know if anyone is dealing with Chef’s multiline output when
shipping to something like logstash->elasticsearch. Currently Chef does
not delineate log entries when they span multiple lines. I’m considering
monkey patching the logger to add a frame around the log entries but I’m
not sure where the best place to do this is? Ideally I would get it
implemented before chef makes a single log entry…

-Greg

On Sun, Mar 2, 2014 at 11:46 PM, Greg Zapp greg.zapp@gmail.com wrote:

I would like to know if anyone is dealing with Chef's multiline output
when shipping to something like logstash->elasticsearch. Currently Chef
does not delineate log entries when they span multiple lines. I'm
considering monkey patching the logger to add a frame around the log
entries but I'm not sure where the best place to do this is? Ideally I
would get it implemented before chef makes a single log entry...

When I've done this in the past, I've just used Logstash's multiline filter
to collapse lines that don't begin with a datestamp in square brackets (as
that's reliably at the beginning of every Chef log line).

Zac

Hi Zac,

I've looked at the multi-line logstash filter's source and it appears to
behave like the nxlog multi-line support; that is the current event is
"pending" until another non-matching event comes through to knock it out.
This is sub-optimal for me. Without adding a hint of some fashion to the
actual logs I can't see a way to have a multi-line event ejected as soon as
it's been completed.

-Greg

On Tue, Mar 4, 2014 at 4:18 AM, Zac Stevens zts@cryptocracy.com wrote:

On Sun, Mar 2, 2014 at 11:46 PM, Greg Zapp greg.zapp@gmail.com wrote:

I would like to know if anyone is dealing with Chef's multiline output
when shipping to something like logstash->elasticsearch. Currently Chef
does not delineate log entries when they span multiple lines. I'm
considering monkey patching the logger to add a frame around the log
entries but I'm not sure where the best place to do this is? Ideally I
would get it implemented before chef makes a single log entry...

When I've done this in the past, I've just used Logstash's multiline
filter to collapse lines that don't begin with a datestamp in square
brackets (as that's reliably at the beginning of every Chef log line).

Zac

What's your end goal? Just to get the data in Logstash, or do you have a
specific view into the data you'd like to see?

If the goal is to get the data into Logstash, you might try forcing the
logger back to single-line mode.

If the goal is as an intermediate hop to a specific view, might I recommend
setting up a post-run handler to directly share the run information you
need?

On Sun, Mar 2, 2014 at 6:46 PM, Greg Zapp greg.zapp@gmail.com wrote:

Hello,

I would like to know if anyone is dealing with Chef's multiline output
when shipping to something like logstash->elasticsearch. Currently Chef
does not delineate log entries when they span multiple lines. I'm
considering monkey patching the logger to add a frame around the log
entries but I'm not sure where the best place to do this is? Ideally I
would get it implemented before chef makes a single log entry...

-Greg

On Mar 2, 2014, at 3:46 PM, Greg Zapp greg.zapp@gmail.com wrote:

Hello,

I would like to know if anyone is dealing with Chef's multiline output when shipping to something like logstash->elasticsearch. Currently Chef does not delineate log entries when they span multiple lines. I'm considering monkey patching the logger to add a frame around the log entries but I'm not sure where the best place to do this is? Ideally I would get it implemented before chef makes a single log entry…

There are a lot of handlers that show how to get structured data out of each Chef run. Send that to your server rather than the raw log output.

--Noah

HI Brian,

Yes, I'm wanting to get all the log data into logstash. I'm looking at the
ruby logger class and I don't see anything about single line mode? It does
take a formatter block so that's likely where I can set up my ambush.
Unfortunately it looks like I will need to customize my Chef client
installation to achieve what I want :expressionless: .

-Greg

On Mon, Mar 3, 2014 at 12:54 PM, Brian Hatfield bmhatfield@gmail.comwrote:

What's your end goal? Just to get the data in Logstash, or do you have a
specific view into the data you'd like to see?

If the goal is to get the data into Logstash, you might try forcing the
logger back to single-line mode.

If the goal is as an intermediate hop to a specific view, might I
recommend setting up a post-run handler to directly share the run
information you need?

On Sun, Mar 2, 2014 at 6:46 PM, Greg Zapp greg.zapp@gmail.com wrote:

Hello,

I would like to know if anyone is dealing with Chef's multiline output
when shipping to something like logstash->elasticsearch. Currently Chef
does not delineate log entries when they span multiple lines. I'm
considering monkey patching the logger to add a frame around the log
entries but I'm not sure where the best place to do this is? Ideally I
would get it implemented before chef makes a single log entry...

-Greg

Do you want all of your Chef logs in Logstash, or do you just want exceptions and Chef run outcomes? If you don’t want all of the logs, the easiest way to handle that is to use a handler like this one: GitHub - lusis/logstash_handler.

  • Larry

On Mar 2, 2014, at 6:41 PM, Greg Zapp greg.zapp@gmail.com wrote:

HI Brian,

Yes, I'm wanting to get all the log data into logstash. I'm looking at the ruby logger class and I don't see anything about single line mode? It does take a formatter block so that's likely where I can set up my ambush. Unfortunately it looks like I will need to customize my Chef client installation to achieve what I want :expressionless: .

-Greg

On Mon, Mar 3, 2014 at 12:54 PM, Brian Hatfield bmhatfield@gmail.com wrote:
What's your end goal? Just to get the data in Logstash, or do you have a specific view into the data you'd like to see?

If the goal is to get the data into Logstash, you might try forcing the logger back to single-line mode.

If the goal is as an intermediate hop to a specific view, might I recommend setting up a post-run handler to directly share the run information you need?

On Sun, Mar 2, 2014 at 6:46 PM, Greg Zapp greg.zapp@gmail.com wrote:
Hello,

I would like to know if anyone is dealing with Chef's multiline output when shipping to something like logstash->elasticsearch. Currently Chef does not delineate log entries when they span multiple lines. I'm considering monkey patching the logger to add a frame around the log entries but I'm not sure where the best place to do this is? Ideally I would get it implemented before chef makes a single log entry...

-Greg

Hi Larry and Noah,

Thanks for the feedback. Currently though I'm working on type "chef_log",
but I will most likely swing back around to "chef_reports" in the future:)
I plan to ship all the output and store a high level of verbosity for a
reduced duration from the rest of the stuff. I'm doing some long Windows
client runs with application/database deploys and it's been really nice to
be able to view all this stuff from one location.

-Greg

On Mon, Mar 3, 2014 at 3:47 PM, Larry Wright larrywright@gmail.com wrote:

Do you want all of your Chef logs in Logstash, or do you just want
exceptions and Chef run outcomes? If you don't want all of the logs, the
easiest way to handle that is to use a handler like this one:
GitHub - lusis/logstash_handler.

  • Larry

On Mar 2, 2014, at 6:41 PM, Greg Zapp greg.zapp@gmail.com wrote:

HI Brian,

Yes, I'm wanting to get all the log data into logstash. I'm looking at
the ruby logger class and I don't see anything about single line mode? It
does take a formatter block so that's likely where I can set up my ambush.
Unfortunately it looks like I will need to customize my Chef client
installation to achieve what I want :expressionless: .

-Greg

On Mon, Mar 3, 2014 at 12:54 PM, Brian Hatfield bmhatfield@gmail.comwrote:

What's your end goal? Just to get the data in Logstash, or do you have a
specific view into the data you'd like to see?

If the goal is to get the data into Logstash, you might try forcing the
logger back to single-line mode.

If the goal is as an intermediate hop to a specific view, might I
recommend setting up a post-run handler to directly share the run
information you need?

On Sun, Mar 2, 2014 at 6:46 PM, Greg Zapp greg.zapp@gmail.com wrote:

Hello,

I would like to know if anyone is dealing with Chef's multiline output
when shipping to something like logstash->elasticsearch. Currently Chef
does not delineate log entries when they span multiple lines. I'm
considering monkey patching the logger to add a frame around the log
entries but I'm not sure where the best place to do this is? Ideally I
would get it implemented before chef makes a single log entry...

-Greg

Hello All,

I have long since resolved this to my satisfaction so thought I should
update here as well. I have created a custom formatter.rb for mixlib-log.
I drop this in after installing chef when preparing my OS images.

Cheers,
-Greg

On Tue, Mar 4, 2014 at 11:25 AM, Greg Zapp greg.zapp@gmail.com wrote:

Hi Zac,

I've looked at the multi-line logstash filter's source and it appears to
behave like the nxlog multi-line support; that is the current event is
"pending" until another non-matching event comes through to knock it out.
This is sub-optimal for me. Without adding a hint of some fashion to the
actual logs I can't see a way to have a multi-line event ejected as soon as
it's been completed.

-Greg

On Tue, Mar 4, 2014 at 4:18 AM, Zac Stevens zts@cryptocracy.com wrote:

On Sun, Mar 2, 2014 at 11:46 PM, Greg Zapp greg.zapp@gmail.com wrote:

I would like to know if anyone is dealing with Chef's multiline output
when shipping to something like logstash->elasticsearch. Currently Chef
does not delineate log entries when they span multiple lines. I'm
considering monkey patching the logger to add a frame around the log
entries but I'm not sure where the best place to do this is? Ideally I
would get it implemented before chef makes a single log entry...

When I've done this in the past, I've just used Logstash's multiline
filter to collapse lines that don't begin with a datestamp in square
brackets (as that's reliably at the beginning of every Chef log line).

Zac

The chef formatter output (well, the default one, anyway) is designed for human consumption, but the same API is available to you to do whatever you want.

Here’s some examples:

The Enterprise Chef reporting code isn’t real-time (AFAIK this is true of the foreman plugin as well), but this is a design choice of the server implementation and not a limitation of the events API in chef-client.

I don’t know of anything that does exactly what you want out of the box, so you’ll have to do some assembling of the parts yourself.

--
Daniel DeLeo

On Sunday, March 2, 2014 at 7:01 PM, Greg Zapp wrote:

Hi Larry and Noah,

Thanks for the feedback. Currently though I'm working on type "chef_log", but I will most likely swing back around to "chef_reports" in the future:) I plan to ship all the output and store a high level of verbosity for a reduced duration from the rest of the stuff. I'm doing some long Windows client runs with application/database deploys and it's been really nice to be able to view all this stuff from one location.

-Greg

On Mon, Mar 3, 2014 at 3:47 PM, Larry Wright <larrywright@gmail.com (mailto:larrywright@gmail.com)> wrote:

Do you want all of your Chef logs in Logstash, or do you just want exceptions and Chef run outcomes? If you don’t want all of the logs, the easiest way to handle that is to use a handler like this one: GitHub - lusis/logstash_handler.

  • Larry

On Mar 2, 2014, at 6:41 PM, Greg Zapp <greg.zapp@gmail.com (mailto:greg.zapp@gmail.com)> wrote:

HI Brian,

Yes, I'm wanting to get all the log data into logstash. I'm looking at the ruby logger class and I don't see anything about single line mode? It does take a formatter block so that's likely where I can set up my ambush. Unfortunately it looks like I will need to customize my Chef client installation to achieve what I want :expressionless: .

-Greg

On Mon, Mar 3, 2014 at 12:54 PM, Brian Hatfield <bmhatfield@gmail.com (mailto:bmhatfield@gmail.com)> wrote:

What's your end goal? Just to get the data in Logstash, or do you have a specific view into the data you'd like to see?

If the goal is to get the data into Logstash, you might try forcing the logger back to single-line mode.

If the goal is as an intermediate hop to a specific view, might I recommend setting up a post-run handler to directly share the run information you need?

On Sun, Mar 2, 2014 at 6:46 PM, Greg Zapp <greg.zapp@gmail.com (mailto:greg.zapp@gmail.com)> wrote:

Hello,

I would like to know if anyone is dealing with Chef's multiline output when shipping to something like logstash->elasticsearch. Currently Chef does not delineate log entries when they span multiple lines. I'm considering monkey patching the logger to add a frame around the log entries but I'm not sure where the best place to do this is? Ideally I would get it implemented before chef makes a single log entry...

-Greg

Hi Daniel,

Thanks for those links; that stuff definitely looks interesting. I think
for grabbing the logs out as they come I may just monkey patch my chef
client to add a frame around what it would normally output to the log.
That should let me grab out multi-line log entries no worries.

-Greg

On Mon, Mar 3, 2014 at 4:12 PM, Daniel DeLeo dan@kallistec.com wrote:

The chef formatter output (well, the default one, anyway) is designed for
human consumption, but the same API is available to you to do whatever you
want.

Here's some examples:

The Enterprise Chef reporting code isn't real-time (AFAIK this is true of
the foreman plugin as well), but this is a design choice of the server
implementation and not a limitation of the events API in chef-client.

I don't know of anything that does exactly what you want out of the box,
so you'll have to do some assembling of the parts yourself.

--
Daniel DeLeo

On Sunday, March 2, 2014 at 7:01 PM, Greg Zapp wrote:

Hi Larry and Noah,

Thanks for the feedback. Currently though I'm working on type
"chef_log", but I will most likely swing back around to "chef_reports" in
the future:) I plan to ship all the output and store a high level of
verbosity for a reduced duration from the rest of the stuff. I'm doing some
long Windows client runs with application/database deploys and it's been
really nice to be able to view all this stuff from one location.

-Greg

On Mon, Mar 3, 2014 at 3:47 PM, Larry Wright <larrywright@gmail.com(mailto:
larrywright@gmail.com)> wrote:

Do you want all of your Chef logs in Logstash, or do you just want
exceptions and Chef run outcomes? If you don't want all of the logs, the
easiest way to handle that is to use a handler like this one:
GitHub - lusis/logstash_handler.

  • Larry

On Mar 2, 2014, at 6:41 PM, Greg Zapp <greg.zapp@gmail.com (mailto:
greg.zapp@gmail.com)> wrote:

HI Brian,

Yes, I'm wanting to get all the log data into logstash. I'm looking
at the ruby logger class and I don't see anything about single line mode?
It does take a formatter block so that's likely where I can set up my
ambush. Unfortunately it looks like I will need to customize my Chef client
installation to achieve what I want :expressionless: .

-Greg

On Mon, Mar 3, 2014 at 12:54 PM, Brian Hatfield <
bmhatfield@gmail.com (mailto:bmhatfield@gmail.com)> wrote:

What's your end goal? Just to get the data in Logstash, or do you
have a specific view into the data you'd like to see?

If the goal is to get the data into Logstash, you might try
forcing the logger back to single-line mode.

If the goal is as an intermediate hop to a specific view, might I
recommend setting up a post-run handler to directly share the run
information you need?

On Sun, Mar 2, 2014 at 6:46 PM, Greg Zapp <greg.zapp@gmail.com(mailto:
greg.zapp@gmail.com)> wrote:

Hello,

I would like to know if anyone is dealing with Chef's multiline
output when shipping to something like logstash->elasticsearch. Currently
Chef does not delineate log entries when they span multiple lines. I'm
considering monkey patching the logger to add a frame around the log
entries but I'm not sure where the best place to do this is? Ideally I
would get it implemented before chef makes a single log entry...

-Greg

On Mar 2, 2014, at 9:48 PM, Greg Zapp greg.zapp@gmail.com wrote:

Thanks for those links; that stuff definitely looks interesting. I think for grabbing the logs out as they come I may just monkey patch my chef client to add a frame around what it would normally output to the log. That should let me grab out multi-line log entries no worries.

The problem with that method is that you will have created a private fork of the chef client, and you won't be able to upgrade easily when the next version comes out. For example, if another SSL 0day type vulnerability was announced tomorrow, and a new version of chef client was created to address that problem, then you'd have to re-patch the new version with your changes.

Having a local fork like this of a piece of code that is well-maintained by someone else is a classic anti-pattern.

It will be a bit more work, but the right way to solve this problem is with your own local handler that you can keep separate from all the rest of the code, and easily bring with you when new versions of chef-client are shipped.

Of course, at the end of the day, if you want to load up a shotgun, pull the hammers back, and aim it at your foot, that's your choice.

--
Brad Knowles brad@shub-internet.org
LinkedIn Profile: http://tinyurl.com/y8kpxu