Permalink
Fetching contributors…
Cannot retrieve contributors at this time
470 lines (300 sloc) 25.3 KB

CloudWatchAppender Build status NuGet version

A CloudWatch appender for log4net. You can configure log4net to direct some of you log events to CloudWatch, making them show up as data points on a graph.

All posts are made asynchronously to CloudWatch via the AWSSDK library for .NET.

News

Resolved issues #14 and #15.

See Replacing the Event Message Parsers.

Supporting .NET 3.5 again and soon to support .NET 5.0

I will maintain a separate project for .NET 3.5 and in the near future also a 5.0 version.

Next step: Default metric filters

CloudWatchLogsAppender and BufferingCloudWatchLogsAppender will in a future version submit MetricFilters by default if a PatternLayout-string is specified.

Installation

To add CloudWatchAppender to your Visual Studio project, run the following command in Package Manager Console or download the source from GitHub.

PM> Install-Package CloudWatchAppender

Configuration

CloudWatchAppender is easy to configure in web.config or app.config. If you've been using log4net you, probably already have the section and some of the elements defined. The following will direct all your logs events to CloudWatch. It will send a value of 1 with unit "Count". The default metric name as well as namespace is "CloudWatchAppender".

<log4net>
    <appender name="CloudWatchAppender" type="CloudwatchAppender.CloudwatchAppender, CloudwatchAppender">
		<accessKey value="YourAWSAccessKey" />
		<secret value="YourAWSSecret" />
		<endPoint value="url or system name like: eu-west-1" />
    </appender>

    <root>
      <appender-ref ref="CloudWatchAppender" />
    </root>
</log4net>

CloudWatchAppender can do more than this. Pretty much anything you can post to CloudWatch via the AWSSDK is supported by the appender in different ways.

To change the default behavior, you can either provide the info in the config-file or as part of the log event message. The former is cleaner in that the code can remain agnostic to the log event endpoint. The latter provides more power and granularity over what is posted. Other appenders that you might have added will the simply output the data as if it were any old message.

Warning Make sure you read about CloudWatch pricing so you'll not get any surprises. Particularly, CloudWatch treats each combination of metric name, namespace and dimension as a different custom metric. You have just 10 free custom metrics. After that they start charging you.

Note In the above example credentials is in clear text and this is not the Amazon recommended way of doing things. See Configuring Credentials and End Point.

BufferingAggregatingCloudWatchAppender

Besides the regular CloudwatchAppender there is the BufferingAggregatingCloudWatchAppender that has several key benefits. Log events are stored in a buffer and only sent to CloudWatch once certain conditions are met, usually when the buffer reaches a certain limit.

The events are assembled to statistics sets so that a minimum number of requests are performed.

This feature can potentially reduce the frequency of http requests to the AWS API by several orders of magnitude. As such it is the recommended appender for most purposes. Use the regular CloudwatchAppender when real time updates to CloudWatch is essential.

Replacing the following in the right place above will post a request to AWS API only after 1000 log events have been recorded by the appender.

 <appender name="CloudWatchAppender" type="CloudWatchAppender.BufferingAggregatingCloudWatchAppender, CloudWatchAppender">
      <bufferSize value="1000"/>

Most usage patterns describes below are applicable to BufferingAggregatingCloudWatchAppender as well.

See BufferingForwardingAppender and BufferingApenderSkeleton for more information on how to customize a buffering appender and set conditions for flushing the event buffer. For example, a TimeEvaluator can be used to trigger a buffer flush at certain time intervals. See my blog for an example of this.

##BufferingCloudWatchLogsAppender

The buffering BufferingCloudWatchLogsAppender targets CloudWatch Logs, i.e. is a quite different beast with different applications and in fact more of a traditional end point for log4net. To be sure, you can also gather metrics from logs published in this way and you may find this useful for certain applications.

Use logs to monitor your instances in real time. It is not yet a replacement for other means of logging primarily because of the limited functionality offered. For example there is no searching.

The appender is set up in much the same way as the BufferingAggregatingCloudWatchAppender, for example:

<appender name="CloudWatchLogsAppender" type="CloudWatchAppender.BufferingCloudWatchLogsAppender, CloudWatchAppender">
  <bufferSize value="100" />
  <lossy value="false" />
  <evaluator type="log4net.Core.TimeEvaluator">
    <interval value="1" />
  </evaluator>
  <accessKey value="AWSSECRETGOESHERE" />
  <secret value="AWSACCESSKEYGOESHERE" />
  <regionendpoint type="Amazon.RegionEndpoint" value="eu-west-1"/>
  <layout type="CloudWatchAppender.Layout.PatternLayout">
    <conversionPattern value="%date [%thread] %-5level %logger [%ndc] - %message" />
  </layout>

  <groupName value="%logger{-1}" />
  <streamName value="localhost" />
</appender>

There are two parameters to note, groupName and streamName. They provide grouping of the log events and are described in the online documentation.

With BufferingCloudWatchLogsAppender you can make requests to the same stream from separate applications although it will have to retry until it gets a hold of the latest sequence token. If requests come often from different applications at approximately the same time, the algorithm will fail. Trim your buffer size and time interval to avoid this.

##CloudWatchLogsAppender

Because collecting log events is sequential in nature and because CloudWatchAppender is designed to post asyncronous requests to AWS, using a the non-buffered version of the appender makes little sense. Use it only if you application requires immediate prioritized posting of log events.

Consider instead using the BufferingCloudWatchLogsAppender with a small buffer size and/or short time interval.

Having said that, CloudWatchLogsAppender will try to resolve ordering conflicts though not in a very smart way. It will easily become overrun and when it does it just keeps making requests to AWS which will return an error. This is retried 10 times.

Most likely the unbuffered CloudWatchLogsAppender will not be developed further. Use BufferingCloudWatchLogsAppender instead.

Config-file

The following example probably has no use in any application but serves to illustrate the capabilities od the appender. It will post a metric with unit Milliseconds and the value 20 at log entry for all loggers using this appender. The metric name will be ProcessingTime and the namespace MyApp/Process. It also attaches a dimension indicating which instance the instance the entry originated from, if used on an AWS instance.

<appender name="CloudWatchAppender" type="CloudwatchAppender.CloudwatchAppender, CloudwatchAppender">
	<accessKey value="YourAWSAccessKey" />
	<secret value="YourAWSSecret" />
	<endPoint value="eu-west-1" />

    <unit value="Milliseconds"/>
    <value value="20"/>
    <metricname value="ProcessingTime"/>
    <namespace value="MyApp/Processor"/>

    <rateLimit value="20"/>

    <dimension type="Amazon.CloudWatch.Model.Dimension">
        <name value="InstanceID"/>
        <value value="%metadata{instanceid}"/>
    </dimension>
</appender>

This normally goes in your app.config or web.config. log4net allows any old xml file to be brought in and this is of course fine for CloudWatchAppender too.

Notice also we've provided the first of ten possible "dimensions". You can specify any string you like for name and value of the dimension. Above, however, we're using a special token for the value, "%metadata{instanceid}". This will be translated to the EC2 instance ID, see Instance Metadata below. In fact, any token recognized by any regular PatternLayout conversion patterns, for instance %logger, will be translated as such.

The rateLimit limits the number of requests sent to CloudWatch to 20 per second. It is not applicable for BufferingAggregatingCloudWatchAppender and will be ignored.

Credentials and End Point

TODO

AWS client config

TODO

Using PatternLayout

The same result as above can be accomplished by using the version of "PatternLayout" provided by CloudWatchAppender and using the format rules outlined below to format the input string to the appender.

  <layout type="CloudWatchAppender.Layout.PatternLayout, CloudWatchAppender">
       <conversionPattern value="%message Value: 20 Milliseconds, MetricName: ProcessingTime, NameSpace: MyApp/Processor, Dimension0: InstanceID: %metadata{instanceid}"/>
  </layout>

Event log message

CloudWatchAppender and its buffered counter part treat log messages differently from the two Logs appenders.

If you pass a string to the logger like this

ILog log = LogManager.GetLogger(typeof(MyClass));
log.Info("These eight words will be ignored by CloudWatchAppender. Value: 20 Milliseconds, MetricName: ProcessingTime " +
		 "these seven words will be ignored too NameSpace: MyApp/Processor, Dimension0: InstanceID: %metadata{instanceid}");

most of it will be ignored by the CloudWatchAppender.

The above message to the logger will behave in the same way as the previous examples. The CloudWatchAppender event message parser will look for recognizable tokens, largely corresponding to the entities and units familiar to CloudWatch. The parser is pretty lenient in what is allowed but also lets unexpected input slip without warning. As the messages get complicated, especially if PatternLayout is used, it is important to understand the conflict resolution rules.

Of course, if there are other appenders listening on the logger, they will handle the string in their way. Most will output the entire string to whatever end point they are designed for. This includes the BufferingCloudWatchLogsAppender which concatenate everything it can't parse into the actual message of to the log event posted to AWS as in the following:

ILog log = LogManager.GetLogger(typeof(MyClass));
log.Info("These thirteen words will be included GroupName: MyApp/Processor " +
		 "in the log event message by BufferingCloudWatchLogsAppender. StreamName: %metadata{instanceid}");

Note that if the PatternLayout is used, either the original one or the one provided in the CloudWatchAppender namespace, the pattern %message or %m (the short hand is deprecated by log4net) must be present in the conversion pattern for the event log message to be observed.

A list of tokens supported by the event parsers can be found below.

The MetricDatum object

log4net permits not just strings as the parameter to the log event method. Any old object will do and normally the ToString() method is used to convert it to a string. First, however, log4net will look to see if an ObjectRenderer has been registered. CloudWatchAppender automatically registers the MetricDatumRenderer, allowing you to provide a MetricDatum to your log message.

The MetricDatum comes in two flavours, the AWS CloudWatch one and the wrapper we have designed. You can use either but our one offers a few more features. Noteably it takes a string to the constructor with which you can provide a message that you want output to appenders other than CloudWatchAppender that you might have registered, a FileAppender maybe. Our version also holds the NameSpace.

Example:

log.Info(new CloudWatchAppender.Model.MetricDatum("A message!")
{
    NameSpace = "MyApp/Processor",
    Dimensions = { new Dimension { Name = "InstanceID", Value = "%metadata{instanceid}" } },
    MetricName = ProcessingTime,
    Unit = StandardUnit.Milliseconds,
    StatisticValues = new StatisticSet
                         {
                             Minimum = 2.1,
                             Maximum = 25.2,
                             Sum = 350.3,
                             SampleCount = 100
                         }
});

or

log.Info(new Amazon.CloudWatch.Model.MetricDatum
{
    Dimensions = { new Dimension { Name = "InstanceID", Value = "%metadata{instanceid}" } },
    MetricName = ProcessingTime,
    Unit = StandardUnit.Milliseconds,
    StatisticValues = new StatisticSet
                         {
                             Minimum = 2,
                             Maximum = 25,
                             Sum = 350,
                             SampleCount = 100
                         }
});

The above will do the same except for the message "A tick!" which, if you have for instance a FileAppender, cannot be output with the latter; and the NameSpace which you would provide some other way: in config, presumably.

ConfigOverrides

Normally input given in parameters to the appenders will override anything given in the log event message, including anything given in the conversion pattern. To change this behaviour, add

<configOverrides value="false"/>

to the appender definition. Now, parameters to the appender will act as defaults, should the values be missing from the message.

Timestamp

As of version 1.2 the timestamp can be set. If left out, CloudWatch will just default it to the current time in UTC.

Set it in your config like so if you use a locale where this format is parsable:

<timestamp value="2012-09-06 14:00:00 +02:00"/>

It works, of course, but you'll find this more useful.

<timestamp value="%utcdate{DATE}"/>

The above uses the log4net PatterConverted for a DateTime-formatted current UTC timestamp. Both the below are permissible in the eventlog message:

"Timestamp: 2012-09-06 12:00:00"

"Timestamp: %date{DATE}"

Both above will be assumed to be UTC, so the second one, at least, may not have expected result. Use utcdate to avoid confusion.

It is recommended to think UTC. That's what CloudWatch does. DateTime.UtcNow will get you the current UTC timestamp. In fact, CloudWatch refuses to display anything in what it deems to be the future, which can be confusing, particularly if you're on the plus side of UTC. You can read about my experiences prior to figuring that one out, on my blog.

Statistics

As well as singles values with unit, CloudWatchAppender supports statistics. This is useful when sending single point values becomes too burdensome. Instead, you aggregate your data to be sent every minute or so. The CloudWatchAppender doesn't go the aggregation for you, you'll have to take care of that yourself. Todo? ;).

Statistics are posted by specifying Minimum, Maximum, Sum and SampleCount. The average is calculated by CloudWatch on the server side as Sum/SampleCount. These entities are all recognized by CloudWatchAppender and used as above, either in the event log message or in the config file.

The following behave the same way.

<unit value="Milliseconds"/>
<sum value="3000"/>
<minimum value="3"/>
<minimum value="400"/>
<samplecount value="250"/>

and

log.Info("unit: milliseconds, sum: 3000, minimum: 3, minimum: 400, samplecount: 250");

Unit conversion

As of version 4.2 you can mix and match units. This is a feature Amazon doesn't provide, it just drops data where the unit doesn't match previously accepted data. But BufferingAggregatingCloudWatchAppender does. As long as the units are physically convertible, as Terabytes and Bits are, for example, the appender will choose the most precise one and convert everyting else in the same request.

As of version 4.3 it will keep track of the unit used between requests, as long as the appender is alive. This means you can mix and match units between regular CloudWatchAppender events as well.

Dimensions

CloudWatch supports up to 10 dimensions given as name/value pair. CloudWatchAppender has no limit but don't try exceeding 10.

In your config file under the appender element you can add dimensions simply by listing a bunch of elements like this:

  <dimension type="Amazon.CloudWatch.Model.Dimension">
    <name value="InstanceID"/>
    <value value="%metadata{instanceid}"/>
  </dimension>

  <dimension type="Amazon.CloudWatch.Model.Dimension">
    <name value="Fruit"/>
    <value value="Apple"/>
  </dimension>

Again, note the metadata pattern.

The corresponding equivalent pattern/event log message would be

"Dimension: InstanceID: %metadata{instanceid}, Dimension: Fruit: Apple" //(%metadata{instanceid} only parsed if in a layout conversion pattern)

or simply

"Dimensions: (InstanceID: %metadata{instanceid}, Fruit: Apple)" //(%metadata{instanceid} only parsed if in a layout conversion pattern)

Deppending on the setting of ConfigOverrides individual dimensions compete according to name (key). Internally in CloudWatchAppender the dimensions are stores as a dictionary.

Using layouts and the CloudWatchAppender PatternLayout

The CloudWatchAppender supports layouts as expected. The most commonly used by far is PatternLayout. You can use the original PatternLayout but it is recommended to use the one provided in the CloudWatchAppender library.

The CloudWatchAppender PatternLayout subclasses PatternLayout so all features should work as expected. Plus there are a few extran functions. Any patterns supported by PatternLayout is headed. Some of them, however, will be less sensible to use in this context. Firstly, some of them take to long and secondly, some will not make sense to CloudWatch or the appender.

Instance metadata

The pattern %metadata{key} anywhere in your conversion pattern will be replaced by the instance metadata indicated by the supplied key of the instance on which the application is running. This information is retrieved via an asynchronous AWS metadata API call at first use and then cached in a static field.

For example, %metadata{instanceid} will provide the instance id and may be useful as a dimension.

Providing the same token, or any other supported token for that matter, in the config-file is also possible and works as expected.

Supported keys are:

  • amiid (ami-id)
  • amilaunchindex (ami-launch-index)
  • amimanifestpath (ami-manifest-path)
  • instanceid (instance-id)
  • instancetype (instance-type)
  • kernelid (kernel-id)
  • localhostname (local-hostname)
  • localipv4 (local-ipv4)
  • mac (mac)
  • availabilityzone (placement/availability-zone)
  • productcodes (product-codes)
  • publichostname (public-hostname)
  • publicipv4 (public-ipv4)
  • publickeys (public-keys)
  • reservationid (reservation-i)

See Instance Metadata.

The old pattern %instanceid is deprecated, but still works.

If you download the source code there is a tiny utility that tests all these keys on your system.

Augmented %logger functionality

The log4net PatternLayout provides the %logger or %c pattern, which translates to the name of the logger, typically the qualified name of the type issuing the event. You can also specify a precision specifier as a integer enclosed in curly brackets following the pattern, to include only the right most elements of the name.

CloudWathcAppender adds support for negative precision specifiers, filtering out the beginning part of the name. This is useful for providing the type and namespace as metric name and namespace respectively to CloudWatch.

Typically you'd create the logger like so.

ILog log = LogManager.GetLogger(typeof(MyClass));

If the namespace is MyApp.MyNamespace, then MetricName: %logger{2} in your pattern would post "MyNamespace.MyClass" as the metric name to CloudWatch.

However, the following may be more suitable for your needs.

MetricName: %logger{1}, NameSpace: %logger{-1}

The negative precision specifier includes only the left elements of the name. The metric name will now by MyClass and the namespace will be MyApp.MyNamespace.

Dots (.) are converted to slashes (/) before sending. This is true of all strings passed as namespace anywhere.

Breaking change as of 4.0: The negative precision specifier used to work slightly differently, clearly not very useful. It stripped the right most elements as a complement to the positive specifier keeping them in. That means that the result was dependent on the number of elements, x less than the number of elements. The new function includes the left most elements which is independent of the number of elements. Rather more useful I think and motivating a breaking change.

RateLimit

Placing the following in the appender config, inhibits the number of request sent to CloudWatch.

<rateLimit value="20"/>

A maximum of 20 per second is sent. This is useful for logging errors which could suddenly spike. The default is not to limit, but it is recommended you do.

Any events exceeding the rate limit will not be processed by the appender. Other appenders my still process the event, of course.

Handling conflicting input

TODO

Tokens recognized by CloudWatchAppender

CloudWatchAppender and BufferingAggregatingCloudWatchAppender

The following are recognized by CloudWatchAppender, BufferingAggregatingCloudWatchAppender and their common event message parser.

Metrics

  • Value
  • Unit
  • Dimension
  • Dimensions
  • NameSpace
  • MetricName
  • Timestamp

Statistics

  • Maximum
  • Minimum
  • SampleCount
  • Sum

Units

This list is based on the SDK type StandardUnit and may not be up to date. StandardUnit is used internally across the code base of CloudWatchAppender to store unit values and to perform string conversion. Whatever StandardUnit supports, CloudWatchAppender does too.

  • Seconds
  • Microseconds
  • Milliseconds
  • Bytes
  • Kilobytes
  • Megabytes
  • Gigabytes
  • Terabytes
  • Bits
  • Kilobits
  • Megabits
  • Gigabits
  • Terabits
  • Percent
  • Count
  • Bytes/Second
  • Kilobytes/Second
  • Megabytes/Second
  • Gigabytes/Second
  • Terabytes/Second
  • Bits/Second
  • Kilobits/Second
  • Megabits/Second
  • Gigabits/Second
  • Terabits/Second
  • Count/Second
  • None

CloudWatchLogsAppender and BufferingCloudWatchLogsAppender

The following are recognized by CloudWatchLogsAppender, BufferingCloudWatchLogsAppender and their common event message parser.

  • Message
  • GroupName
  • StreamName
  • Timestamp

Replacing the Event Message Parsers

In order to avoid the appenders recognizing and removing the above reserved keywords from your message, or provide custom parsing, you may replace the message parser with a custom one. For your convenience we have provided DummyLogsEventMessageParser. This is easily done in config.

With te following config, Message: my important message will be forwarded to CloudWatchLogs as is.

<appender name="CloudWatchLogsAppender" type="CloudWatchAppender.BufferingCloudWatchLogsAppender, CloudWatchAppender">
  //Other config here...
  <eventMessageParser type="CloudWatchAppender.Parsers.DummyLogsEventMessageParser"/>        
</appender>

Some more reading

Check out the following blog posts that seeded the project.

A CloudWatch appender for log4net

Improving the CloudWatch Appender

Introducing the Buffering and Aggregeting CloudWatch Appender

Debugging

TODO

endorse