Level up logs and ELK - Contract first log generator - HTML and Java generation from descriptor file.

Articles index:

1. Introduction (Everyone)
2. JSON as logs format (Everyone)
3. Logging best practices with Logback (Targetting Java DEVs)
4. Logging cutting-edge practices (Targetting Java DEVs) 
5. Contract first log generator (Targetting Java DEVs)
6. ElasticSearch VRR Estimation Strategy (Targetting OPS)
7. VRR Java + Logback configuration (Targetting OPS)
8. VRR FileBeat configuration (Targetting OPS)
9. VRR Logstash configuration and Index templates (Targetting OPS)
10. VRR Curator configuration (Targetting OPS)
11. Logstash Grok, JSON Filter and JSON Input performance comparison (Targetting OPS) 

 Contract first log generator - HTML and Java generation from descriptor file.

 As a result of my previous article,Logging best practices with Logback and Logging cutting-edge practices, I came to the conclusion that we were putting to much weight into developers alone to generate top quality logs.

Nowadays it wouldn't be acceptable by many people to live with code full of hard-coded keys that need to be kept in mind, types to relate and never mistake, and explain all this to other colleagues not only from development teams, but from support, pre-sales, etc...

I see no better alternative than creating a description file that relates domain, type and explanation, something I could convert to HTML and code alike:

version: 1

project-name: coins-jdk8-example

mappings:
  - name: amount
    type: java.lang.Integer
    description: Amount of money to match, in minimum representation (no decimals).
  - name: combinations
    type: java.lang.Integer
    description: Total number of combinations of change.
  - name: coins
    type: int
    description: Number of coins in a combination.

Generated code:

package com.navid.codegen;

import static net.logstash.logback.argument.StructuredArguments.keyValue;

import java.lang.Integer;
import java.lang.Iterable;
import net.logstash.logback.argument.StructuredArgument;

public final class LoggerUtils {
  public static StructuredArgument kvAmount(Integer amount) {
    return keyValue("amount",amount);
  }

  public static StructuredArgument aAmount(Iterable amount) {
    return new net.logstash.logback.marker.ObjectAppendingMarker("amount",amount);
  }

  public static StructuredArgument aAmount(Integer... amount) {
    return new net.logstash.logback.marker.ObjectAppendingMarker("amount",amount);
  }

  public static StructuredArgument kvCombinations(Integer combinations) {
    return keyValue("combinations",combinations);
  }

  public static StructuredArgument aCombinations(Iterable combinations) {
    return new net.logstash.logback.marker.ObjectAppendingMarker("combinations",combinations);
  }

  public static StructuredArgument aCombinations(Integer... combinations) {
    return new net.logstash.logback.marker.ObjectAppendingMarker("combinations",combinations);
  }

  public static StructuredArgument kvCoins(int coins) {
    return keyValue("coins",coins);
  }

  public static StructuredArgument aCoins(Iterable coins) {
    return new net.logstash.logback.marker.ObjectAppendingMarker("coins",coins);
  }

  public static StructuredArgument aCoins(int... coins) {
    return new net.logstash.logback.marker.ObjectAppendingMarker("coins",coins);
  }
}

And HTML description code

After a second evolution, talking with my colleagues while I was presenting this idea, they feed back with the idea of adding complete log sentences instead of just key-type-description triplets.

This would be specially useful for non-coders and other teams, as they would know what to look for in the logs without needing to read it all.

version: 1
project-name: coins-jdk8-example
mappings:
  - name: amount
    type: java.lang.Integer
    description: Amount of money to match, in minimum representation (no decimals).
  - name: combinations
    type: java.lang.Integer
    description: Total number of combinations of change.
  - name: coins
    type: int
    description: Number of coins in a combination.
  - name: iid
    type: java.util.UUID
    description: Interaction id, basically like a request id.
sentences:
  - code: ResultCombinations
    message: "Number of combinations of getting change"
    variables:
      - amount
      - combinations
    extradata: {}
    defaultLevel: info
  - code: ResultMinimum
    message: "Minimum number of coins required"
    variables:
      - amount
      - coins
    extradata: {}
    defaultLevel: info
context:
  - iid

Generated code (removing repeated code from above)

public static void auditResultCombinations(Logger logger, Integer amount, Integer combinations) {
    logger.info("Number of combinations of getting change {} {}",kvAmount(amount),kvCombinations(combinations));
  }

  public static void auditResultCombinations(TriConsumer logger, Integer amount,
      Integer combinations) {
    logger.accept("Number of combinations of getting change {} {}",kvAmount(amount),kvCombinations(combinations));
  }

  public static void auditResultMinimum(Logger logger, Integer amount, int coins) {
    logger.info("Minimum number of coins required {} {}",kvAmount(amount),kvCoins(coins));
  }

  public static void auditResultMinimum(TriConsumer logger, Integer amount, int coins) {
    logger.accept("Minimum number of coins required {} {}",kvAmount(amount),kvCoins(coins));
  }

  public static void setContextIid(UUID iid) {
    org.slf4j.MDC.put("ctx.iid",String.valueOf(iid));
  }

  public static void removeContextIid() {
    org.slf4j.MDC.remove("iid");
  }

  public static void resetContext() {
    org.slf4j.MDC.clear();
  }

  public interface MonoConsumer {
    void accept(String var1);
  }

  public interface BiConsumer {
    void accept(String var1, Object var2);
  }

  public interface TriConsumer {
    void accept(String var1, Object var2, Object var3);
  }

  public interface ManyConsumer {
    void accept(String var1, Object... var2);
  }

Generated code follows all the principles I have been elaborating before:

1. As developers are not typing the name of the Structured Argument, they won't make typos, upper-lower case mistakes, etc. Same concept won't be reused alongside code. Same concept will always have same name, perfectly written each time.
2. As generated code is strongly typed, we are removing another danger from the road. At the same time, generated code allows single, collection and arrays of the same type, trying to make it comfortable for the developer at the same time.
3. Compatible with the idea of forbidding developers to use their own StructuredArguments key-value pairs on the code.
4. Generates HTML code to share with other teams, explaining mappings and sentences to search for.

Final HTML Documentation (including MDC and Sentences)

Role responsibilities are now as follows:

Business / Product Owner / Product Manager / B.I. Analyst
- Ask for introduction of main KPIs that they could later on map in charts or dashboards in order to measure whether the system is doing that it is suppose to do in business words.
This value is usually offered from developers to business, this time they would know they have a tool to ask for this information themselves.

Developers:
- Introduce information related to performance, audit of actions, transactions, etc...
- Introduce those sentences asked by other teams to make their life easier.

Maintainers/ On Callers/ Supports
- Introduce or ask for introduction for some specific well known errors in logs, being them documented first in the descriptor files. We could be aiming for a collection of error codes.
- They can elaborate log based alerts using descriptor file to know what's available.

Missing or future features:

• Maven plugin (currently only Gradle is supported)
• Support for more JDK versions (currently 1.7 and 1.8 supported).
• Improve HTML aspect.
• Redo the tool, it's my first time in Kotlin and I am a bit ashamed to be honest.
• Support for other languages, even not JVM based.
• Support for other Java logging framework.
• Create Elastalert configuration for error messages, maybe for other products as well.
• Suport for varargs and collections in sentences part.
• Extradata field to do something really.
• MDC Closeable function

To be honest, the more I work with this approach, the more I like it. I cannot but invite you to try:
Gradle plugin with working examples: https://github.com/albertonavarro/loggergenerator-gradle-plugin
Standalone tool: https://github.com/albertonavarro/loggergenerator


Next: 6 - ElasticSearch VRR Estimation Strategy

Level up logs and ELK - Logging Cutting-Edge Practices - Documenting and sharing your most important logged information

 

Articles index:

1. Introduction (Everyone)
2. JSON as logs format (Everyone)
3. Logging best practices with Logback (Targetting Java DEVs)
4. Logging cutting-edge practices (Targetting Java DEVs) 
5. Contract first log generator (Targetting Java DEVs)
6. ElasticSearch VRR Estimation Strategy (Targetting OPS)
7. VRR Java + Logback configuration (Targetting OPS)
8. VRR FileBeat configuration (Targetting OPS)
9. VRR Logstash configuration and Index templates (Targetting OPS)
10. VRR Curator configuration (Targetting OPS)
11. Logstash Grok, JSON Filter and JSON Input performance comparison (Targetting OPS)

Logging cutting-edge practices: Sharing your log strategy with other teams and departments

Once you have your ELK cluster in place, and your team is making an application (or several) logging into it, you still have a problem to solve.

Given either of the following scenarios:

• A team newcomer is asked to investigate something that involves logs.
• CTO has granted Support access to ELK so they can have some insights to application activity or problems.
• Another team is investigating a cross-application problem.

Assuming they know the service, host and other common OPS-depending attributes...

• What attributes can they query in ELK?
• What to they mean?
• What text does come with the data they need?
• How do they know what data is correlated?

Bonus question

• How do you enforce that same attribute has same name in all your logs? Moreover, how do you enforce it's always the same type?

I'll be proposing a number of different solutions in a iterative evolution, pick the one you prefer.

Baseline:

You are using  latest log format and best practices from Level up logs and ELK - Logging best practices with Logback

logger.info("New Market Status {} {}", kv("marketId", 1234), kv("newStatus", "ready"));

Cons:

• Name or case could differ for same concept in different names.
• Type mismatch is possible, same name, different type.
• Enforcing usage as policy.
• Not documentation available for sharing with other teams or for your own reference.

 

Iteration #1: Constant names

First problem to solve is ensuring we are not using different keys for the same concept.
Initially there's nothing that avoided this to happen:

logger.info("New Market Status {} {}", kv("marketId", 1234), kv("newStatus", "ready"));

[...] 

logger.info("Editing Market Status {} {}", kv("id", 1234), kv("newstatus", "ready"));

On one hand, no developer is going to manually check all the names for any variable to enforce consistency of names. On the other, even lower/upper case mismatch could ruin your queries as they are stored in case sensitive fields.

First iteration would make us think of a set of constant Strings or Enums to help us to deal with variety of names. Documentation about meaning, usage, required type and description could be explicit in comments.

public class LoggerUtils {
    public static final String MK_ID = "marketId"; //String - Market Id
    public static final String MK_NEW_STATUS = "newStatus"; //MarketStatus.java enum - New Market Status
}

Finally code would look like this (Enforced by code review and good will only)

logger.info("New Market Status {} {}", kv(MK_ID, 1234), kv(MK_NEW_STATUS, "ready"));

[...] 

logger.info("Editing Market Status {} {}", kv(MK_ID, 1234), kv(MK_NEW_STATUS, "ready"));

Cons:

• Name or case could differ for same concept in different names.
• Type mismatch is possible: same name, different type.
• Enforce usage as policy.
• Not documentation available for sharing with other teams or for your own reference.

Iteration #2: Enforcing types

This problem comes from accidentally reusing same name for different kinds of items, being "id" a paradigmatic example.

logger.info("New Market Status {} {}", kv("id", 1234), kv("newStatus", "ready"));

[...] 

logger.info("User has signed up {}", kv("id", "email@forexample.com"));

Unless forced, first occurrence of a type defines the type for that index. Therefore you will find an error as following in Logstash logs/output:

logstash_1       | [2018-11-15T22:08:29,392][WARN ][logstash.outputs.elasticsearch] 

Could not index event to Elasticsearch. {

:status=>400, 

:action=>[

  "index", {

    :_id=>nil, 

    :_index=>"vrr-leveluplogging-low-2018-11-15", 

    :_type=>"doc", 

    :_routing=>nil

  }, 

  #<LogStash::Event:0x9b41f3e>

], 

:response=>{

  "index"=>{

    "_index"=>

    "vrr-leveluplogging-low-2018-11-15", 

    "_type"=>"doc", 

    "_id"=>"hJZrGWcBSDbbRtN6HHw3", 

    "status"=>400, 

    "error"=>{

      "type"=>"illegal_argument_exception", 

      "reason"=>"mapper [id] of different type, current_type [long], merged_type [text]"

}}}}

If you check Kibana's Management -> Index Patterns -> vrr-* (in our example)


Field "id" has been defined as "number", therefore when Logstash tries to put a "string" it fails.

Once introduced the problem, let's try the solution.

import net.logstash.logback.argument.StructuredArgument;
import static net.logstash.logback.argument.StructuredArguments.kv;

public class LoggerUtils {

    public static StructuredArgument logMarketId(Long id) {
        return kv("marketId", id);
    }

    public static StructuredArgument logCustId(String id) {
        return kv("custId", id);
    }

}

We could create a helper class that centralized the responsibility of not reusing names, and name-type relationship.

It would be used like this now (old and new version):
logger.info("User has signed up {}", kv("id", "email@forexample.com"));

logger.info("User has signed up {}", logCustId("email@forexample.com"));

Yet you need to enforce creating these functions and its usage.

Cons:

• Name or case could differ for same concept in different names
• Type mismatch is possible, same name, different type
• Enforce usage as policy
• Not documentation available for sharing with other teams or for your own reference

Please notice that a field accepting a type, e.g. "id" accepting "number", also implies that it can take an array of the same type (and not only a single value); it will be handled by ElasticSearch transparently. They will be indexed as searches will return the same document for a query of either of the values in the array.

Iteration #3: Enforcing usage

How to avoid that a random developer adds their own log lines, breaking all the rules above? Good and Rogue developer below:

import net.logstash.logback.argument.StructuredArgument;
import org.slf4j.Logger;import org.slf4j.LoggerFactory; 
import static example.LoggerUtils.logCustId;
import static net.logstash.logback.argument.StructuredArguments.kv; 

[...] 

logger.info("Good developer using custom LoggerUtils {}", logCustId("email@forexample.com")); 

[...] 

logger.info("Roge developer not using custom LoggerUtils {}", kv("custId",1234L));


Fortunately for us, Checkstyle already allows to control arbitrary imports, and also allows suppresion of this rule for a given class. Let's put it together.

Checkstyle configuration forbidding usage of kv import in the project:

<module name="Checker">
    <property name="charset" value="UTF-8">

    <module name="SuppressionFilter">
        <property name="file" value="${config_loc}/suppressions.xml">
    </property></module>
    
    <module name="TreeWalker">
        <module name="IllegalImport">
            <property name="illegalClasses" value="net\.logstash\.logback\.argument\.StructuredArguments.*">
            <property name="regexp" value="true">
        </property></property></module>
    </module>
</property></module>

Making an exception with LoggerUtils class:

<suppressions>
    <suppress checks="IllegalImport" files="LoggerUtils\.java"></suppress>

</suppressions>

You could argue that there are ways to avoid this prohibition, I agree, always are.
Goal here is not to avoid by all means that a Rogue developer logged anything he liked. Goal is to avoid mistakes, and programmatically bypass this checks should really shine in a code review.

As a result of applying above configuration in our favorite build tool (Maven, Gradle, etc..) you would find a broken build (if you configure it so, and so I recommend) and an explanation as follows (Gradle output):

:compileJava
:processResources UP-TO-DATE
:classes

[ant:checkstyle] [ERROR] /home/alberto/code/leveluplogging/leveluplogging/src/main/java/example/ErrorType.java:9:1: 

Illegal import - net.logstash.logback.argument.StructuredArguments.kv. [IllegalImport]
:checkstyleMain FAILED

FAILURE: Build failed with an exception.

Cons:

• Name or case could differ for same concept in different names.
• Type mismatch is possible: same name, different type.
• Enforce usage as policy.  
• Not documentation available for sharing with other teams or for your own reference.

 

Iteration #4: Contract-first LoggerUtils code generation

A solution that kept the goodness of the three previous iterations, but focused on a "documentation first" approach (analogy of contract-first for developers) would involve, in my opinion, the following elements:

1. A description file that explains in the closest to human language possible what are you logging that could be of any interest to anyone.
2. A code generator application that took the description file and made some equivalent to LoggerUtils in your favorite language. 
3. A documentation generator application that took the description file and made a full human readable documentation in your favorite markup / text format.
4. A plugin to attack previous two steps in your build chain (Gradle plugin, Maven plugin..)

This topic will take me long enough to deserve another article. See link below "Next"
 




Next: 5 - Contract first log generator

Level up logs and ELK - Logstash Grok, JSON Filter and JSON Input performance comparision

Articles index:

1. Introduction (Everyone)
2. JSON as logs format (Everyone)
3. Logging best practices with Logback (Targetting Java DEVs)
4. Logging cutting-edge practices (Targetting Java DEVs) 
5. Contract first log generator (Targetting Java DEVs)
6. ElasticSearch VRR Estimation Strategy (Targetting OPS)
7. VRR Java + Logback configuration (Targetting OPS)
8. VRR FileBeat configuration (Targetting OPS)
9. VRR Logstash configuration and Index templates (Targetting OPS)
10. VRR Curator configuration (Targetting OPS)
11. Logstash Grok, JSON Filter and JSON Input performance comparison (Targetting OPS)

Logstash Grok, JSON Filter and JSON Input performance comparison

As part of the VRR strategy altogether, I've performed a little experiment to compare performance for different configurations.

I keep using the FileBeat -> Logstash -> Elasticsearch <- Kibana, this time everything updated to 6.4.1 using Docker.

Experiment consist on letting FileBeat read a file containing 3 million entries, generated in JSON (923000198 bytes) and plain text (492000055 bytes) by a modified version of VRR.java. Logstash will be reading from the beats plugin and will use the information within to redirect these lines to the most suitable index (1m to critical, 1m to important, 1m to low).

Monitoring is enabled from Kibana and Logstash so all the information is collected and stored in ElasticSearch itself.

Given everything is running in the same box, under the same concurrent load (none), same CPU, memory and disk profile, and same cluster configuration (one ElasticSearch in total), this result is not a representative result for throughput in any case, however, it should be a valid experiment for performance comparison.

 Logstash + Grok Filter + KV Filter

This configuration takes input from Beats input, uses Grok to take some fields apart (message, timestamp, rid, loglevel..), then applies KV to find key-value pairs in the text, finally uses the information from key-value to choose index.

input {
  beats {
    port => 5044
  }
}

filter {
    grok {
        match => [ "message" , "%{TIME:@timestamp} %{UUID:rid} \[%{WORD:thread}\] 

%{LOGLEVEL:loglevel}\s+%{WORD:classname} - %{GREEDYDATA:message}" ]
        overwrite => ["message"]
}

kv {

}
}

output {
        if [importance] == "CRIT" { 
            elasticsearch { 
                hosts => "elasticsearch:9200"
                index => "vrr-%{[fields][service]}-crit-%{+YYYY-MM-dd}" 
                template => "templates/template-max.json" 
                template_overwrite => true
                template_name => "vrr-max"
            }
        } else if [importance] == "IMP" { 
            elasticsearch { 
                hosts => "elasticsearch:9200"
                index => "vrr-%{[fields][service]}-imp-%{+YYYY-MM-dd}" 
                template => "templates/template-mid.json" 
                template_overwrite => true
                template_name => "vrr-mid"
            }
        } else { 
            elasticsearch { 
                hosts => "elasticsearch:9200"
                index => "vrr-%{[fields][service]}-low-%{+YYYY-MM-dd}" 
                template => "templates/template-min.json" 
                template_overwrite => true
                template_name => "vrr-min"
            }
        }
        
  
}

 

Results:

• 1 million entries per each VRR index, OK
• Around 600 events per seconds went through Logstash, processing each one in approximately 1500 micro seconds (just above really)
• CPU averages between 20% and 25%

 

Logstash + JSON Filter

In this case we are using a JSON log file with the same amount of information, and will be extracted using JSON filter plugin in Logstash. After that, sending to the right index based on the extracted information.

input {
  beats {
    port => 5044
  }
}

filter {
    if [fields][logschema] == "vrr" {
        json {
            source => "message"
        }
    }
}

output {
     if [fields][logschema] == "vrr" { 
        if [importance] == "CRIT" { 
            elasticsearch { 
                hosts => "elasticsearch:9200"
                index => "vrr-%{[fields][service]}-crit-%{+YYYY-MM-dd}" 
                template => "templates/template-max.json" 
                template_overwrite => true
                template_name => "vrr-max"
            }
        } else if [importance] == "IMP" { 
            elasticsearch { 
                hosts => "elasticsearch:9200"
                index => "vrr-%{[fields][service]}-imp-%{+YYYY-MM-dd}" 
                template => "templates/template-mid.json" 
                template_overwrite => true
                template_name => "vrr-mid"
            }
        } else { 
            elasticsearch { 
                hosts => "elasticsearch:9200"
                index => "vrr-%{[fields][service]}-low-%{+YYYY-MM-dd}" 
                template => "templates/template-min.json" 
                template_overwrite => true
                template_name => "vrr-min"
            }
        }
        
    } else { 
        elasticsearch {
            hosts => "elasticsearch:9200"
            index => "logstash-classic-%{[fields][service]}-%{+YYYY-MM-dd-HH}" 
        }
    }
}

 

Results

• 1 million entries per each VRR index, OK
• Around 875 events per seconds went through Logstash, processing each one in approximately 1150 micro seconds.
• CPU averages between 15% and 20%

Logstash + JSON Input

Only difference with previous test is that JSON is applied at entry level instead of filter level, for my own sake, I really wanted to know what's the difference.

input {
  beats {
    port => 5044
    codec => json
  }
}

output {
     if [fields][logschema] == "vrr" { 
        if [importance] == "CRIT" { 
            elasticsearch { 
                hosts => "elasticsearch:9200"
                index => "vrr-%{[fields][service]}-crit-%{+YYYY-MM-dd}" 
                template => "templates/template-max.json" 
                template_overwrite => true
                template_name => "vrr-max"
            }
        } else if [importance] == "IMP" { 
            elasticsearch { 
                hosts => "elasticsearch:9200"
                index => "vrr-%{[fields][service]}-imp-%{+YYYY-MM-dd}" 
                template => "templates/template-mid.json" 
                template_overwrite => true
                template_name => "vrr-mid"
            }
        } else { 
            elasticsearch { 
                hosts => "elasticsearch:9200"
                index => "vrr-%{[fields][service]}-low-%{+YYYY-MM-dd}" 
                template => "templates/template-min.json" 
                template_overwrite => true
                template_name => "vrr-min"
            }
        }
        
    } else { 
        elasticsearch {
            hosts => "elasticsearch:9200"
            index => "logstash-classic-%{[fields][service]}-%{+YYYY-MM-dd-HH}" 
        }
    }
}

Results:

• 1 million entries per each VRR index, OK
• Around 1000 events per seconds went through Logstash, processing each one in approximately 1000 micro seconds.
• CPU averages around 15%

 

Conclusions:

Using Grok with KV is the slowest option.
Using JSON as input is the fastest option, but reduces the flexibility of having several formats in the same input. This can be mitigated with different pipelines and ports.
Using JSON as filter provides the same flexibility than Grok without the big performance penalty. It is slower than JSON as input though.

Level up logs and ELK - ElasticSearch Replication Factor and Retention - VRR Estimation Strategy

Articles index:

1. Introduction (Everyone)
2. JSON as logs format (Everyone)
3. Logging best practices with Logback (Targetting Java DEVs)
4. Logging cutting-edge practices (Targetting Java DEVs) 
5. Contract first log generator (Targetting Java DEVs)
6. ElasticSearch VRR Estimation Strategy (Targetting OPS)
7. VRR Java + Logback configuration (Targetting OPS)
8. VRR FileBeat configuration (Targetting OPS)
9. VRR Logstash configuration and Index templates (Targetting OPS)
10. VRR Curator configuration (Targetting OPS)
11. Logstash Grok, JSON Filter and JSON Input performance comparison (Targetting OPS)

ElasticSearch VRR Estimation Strategy

Estimating how much storage is needed by ElasticSearch to store your logs depends on three variables mostly.

• Replication factor: ElasticSearch can allocate copies of your logs in distributed nodes so it becomes fault tolerant. If a node dies, other can continue with reading and writing info for that index/shard.

• Retention: ElasticSearch is unable to choose by itself for how long data will be kept. However other tools like Curator can help to define this variable. Curator will be our option in this series of articles.

• Volume: Logs to be stored, it's an obvious variable.

We are not going to consider other variables, but feel free to dig in anytime with this document from the horse's mouth The true story behind Elasticsearch storage requirements.

Monolithic estimation strategy

In order to estimate the storage needed by an application across all ElasticSearch nodes, you'll need to make the following simple calculation:

replication factor * retention (days) * volume (per day) = total storage needed.

One of my clients had 4TB of logs per day (averaged), let's make some numbers:
4TB/day * 365 days retention requiered * 3 copies = 4380TB storage required.
Someone suffered a heart attack in that meeting...

Variable-retention-replication (VRR) estimation strategy

Previous calculation has an implicit assumption, all information from the same file share the same importance, therefore same retention and replication factor. As a software developer and log generator, I know that's radically false.

The only way to solve this problem is to admit that not all the information in an application log file is equally important. If we consider three categories, "low importance", "important", "critical", we would need all project managers to define their logs' importance as a matrix of "importance percentage", "retention" and "replication" almost line by line (VRR matrix).

VRR (Variable Replication and Retention) Matrix for example application:

Being generous, most of the logs from the example application are useless after one or two weeks, they are only useful to investigate problems if they arose. This is purely debug information. In order to be conservative in calculations, we'll say it's 89% and it is required for two weeks retention with no replication (1 copy in total).

Around 10% of example application logs could be considered important, they are user tracking/activity, application events and synthetic information about errors. From this information we are creating most of the dashboards as well, and for that reason we need replication too (replication helps with search performance). 10% of the logs are required for three months retention and single-replication (2 copies in total).

Around 1% of example application logs are critical, information like user audit, log-in activity and product hiring / purchases events. 1% of the logs are required for 53 weeks retention and double-replication (3 copies in total, it's important not to lose this information).

Example application VRR Matrix:

Importance	Percentage	Retention	Replication
Debug	89%	14 days	1 copy
Important	10%	90 days	2 copies
Critical	1%	371 days	3 copies

As an academical example, let's apply this matrix to the 4TB we mentioned before, knowing there would be a VRR matrix per application and those 4TB belonged to dozens of them.
The hypothetical result would be:

4TB * (0.89 * 14 * 1 + 0.10 * 90 * 2 + 0.01 * 371 * 3 ) = 166TB

By these numbers, we just need 166TB to cover a year round of logs, that's 3% of the originally estimated 4380TB we calculated with the monolithic strategy.

Maybe comparing with an entire year of 3 copies of everything it's a bit too much, let's compare with other strategies:

• 1 Month 3 copies monolithic strategy -> 372TB, more than double

• 1 Year 1 copy monolithic stragegy -> 1484TB, 9 times more (this is almost the 90% promised in the clickbait!)

You need to go as low as 2 weeks 3 copies to find a comparable size -> 168TB. Now, what do you prefer?

a) 1 Year 3 Copies for critical info, 3 months 2 copies for important, 2 weeks single copy for the rest or..

b) 3 copies 2 weeks for everything.

How VRR translates to configuration?

Replication is an index property, this is telling us we need a different index per "importance". We need to tell ElasticSearch what's the replication policy when we create the index (it could be told after creation, but this is just more comfortable).
See VRR Logstash configuration

Retention is a curator policy that we will apply per-index.
See VRR Curator configuration

Logstash will create the indices in ElasticSearch depending on the importance using index-templates. We need to put different "importance" logs in different indices. Logstash can do that as long as these logs are "tagged" in a way Logstash understands (e.g. JSON fields in the logs).
See VRR Logstash configuration and VRR FileBeat configuration

Logs in JSON format can be easily tagged without extra OPS time, untagged logs will be assimilated as the lowest importance so it's developer responsibility to tag them.
See VRR Java + Logback configuration

Steps to implement VRR Strategy

1. Developers need to tag all lines of logs with the "importance" on them. As explained before, if they used JSON, it would be easier for everyone. Untagged logs will be considered of the lowest importance.
2. Project managers and developers need to define VRR Matrix to estimate log storage requirements for OPS.
3. For all application implementing VRR, OPS need to use one single special entry in Logstash to create importance-dependent indices in ElasticSearch using VRR matrix information. Index name will contain service name, date and importance so curator can distinguish them. They also need to change Index Templates accordingly.
4. Curator configuration to be aware of VRR matrix to remove information as soon as allowed.

OPS will tell you to please have a common VRR policy for all applications, it's easier to manage. It's not a crazy request and you's still  be in a much better place than you used to be anyway.


Next: 7 - VRR Java + Logback configuration

Level up logs and ELK - VRR Curator configuration

Articles index:

1. Introduction (Everyone)
2. JSON as logs format (Everyone)
3. Logging best practices with Logback (Targetting Java DEVs)
4. Logging cutting-edge practices (Targetting Java DEVs) 
5. Contract first log generator (Targetting Java DEVs)
6. ElasticSearch VRR Estimation Strategy (Targetting OPS)
7. VRR Java + Logback configuration (Targetting OPS)
8. VRR FileBeat configuration (Targetting OPS)
9. VRR Logstash configuration and Index templates (Targetting OPS)
10. VRR Curator configuration (Targetting OPS)
11. Logstash Grok, JSON Filter and JSON Input performance comparison (Targetting OPS)

VRR Curator configuration

 

Curator configuration

Last piece of the puzzle, Curator will take care of deleting information from ElasticSearch once it has expired according to our policies.

There are two ways of deleting information from ElasticSearch using its API

1. By deleting documents through a query that uses timestamp -> SLOW, deleting a document requires modifying indices and caches.
2. By deleting indices as a whole -> FAST. But you cannot choose what to delete inside an index, it all goes down.

The best way of deleting indices but only old information is to create an index per day (or other granularity) and let curator understand the day format from the index name.
Then curator can delete the oldest indices and keep the newest at the same time.

Finally, Curator is not a daemon, it needs to be executed, normally once a day is enough (really as often as your smaller granularity).

Configuration example:

File available here

---
actions:
  1: <- Sets an order of execution
    action: delete_indices <- action
    description: >-
      Delete indices older than 3 days (based on index name), for vrr-*-crit-
      prefixed indices. Application/Service name is irrelevant, but this only 
      applies to "crit" indices. Ignore the error if the filter does not result in an
      actionable list of indices (ignore_empty_list) and exit cleanly.
    options:
      ignore_empty_list: True
      timeout_override:
      continue_if_exception: False
      disable_action: False <- otherwise it wouldn't execute
    filters:
    - filtertype: pattern
      kind: regex
      value: vrr-.*-crit- <- Applies to all VRR critical indices, no matter the application. 

this is only valid if you get an agreement on retention being the same for all application for

the same importance. 
      exclude:
    - filtertype: age <- Second filter, we are filtering by age
      source: name
      direction: older
      timestring: '%Y-%m-%d' <- date format in the index (set in logstash!)
      unit: days
      unit_count: 371 <- delete if older than 371 days ("days" defined in unit, just above)
      exclude:
  2:
    action: delete_indices
    description: >-
      Delete indices older than 2 days (based on index name), for vrr-*-imp-
      prefixed indices. Application/Service name is irrelevant, but this only 
      applies to "imp" indices. Ignore the error if the filter does not result in an
      actionable list of indices (ignore_empty_list) and exit cleanly.
    options:
      ignore_empty_list: True
      timeout_override:
      continue_if_exception: False
      disable_action: False
    filters:
    - filtertype: pattern
      kind: regex
      value: vrr-.*-imp- <- Applies to all VRR important indices
      exclude:
    - filtertype: age
      source: name
      direction: older
      timestring: '%Y-%m-%d'
      unit: days
      unit_count: 90 <- delete if older than 90 days
      exclude:
  3:
    action: delete_indices
    description: >-
      Delete indices older than 1 days (based on index name), for vrr-*-low-
      prefixed indices. Application/Service name is irrelevant, but this only 
      applies to "low" indices. Ignore the error if the filter does not result in an
      actionable list of indices (ignore_empty_list) and exit cleanly.
    options:
      ignore_empty_list: True
      timeout_override:
      continue_if_exception: False
      disable_action: False
    filters:
    - filtertype: pattern
      kind: regex
      value: vrr-.*-low- <- Applies to all VRR low indices
      exclude:
    - filtertype: age
      source: name
      direction: older
      timestring: '%Y-%m-%d'
      unit: days
      unit_count: 14 <- delete if older than 14 days
      exclude:

Next: 11 - Logstash Grok, JSON Filter and JSON Input performance comparison

Level up logs and ELK - VRR FileBeat configuration

Articles index:

1. Introduction (Everyone)
2. JSON as logs format (Everyone)
3. Logging best practices with Logback (Targetting Java DEVs)
4. Logging cutting-edge practices (Targetting Java DEVs) 
5. Contract first log generator (Targetting Java DEVs)
6. ElasticSearch VRR Estimation Strategy (Targetting OPS)
7. VRR Java + Logback configuration (Targetting OPS)
8. VRR FileBeat configuration (Targetting OPS)
9. VRR Logstash configuration and Index templates (Targetting OPS)
10. VRR Curator configuration (Targetting OPS)
11. Logstash Grok, JSON Filter and JSON Input performance comparison (Targetting OPS)

VRR FileBeat configuration

Filebeat doesn't need much configuration for JSON log files, just our typical agreement between parties:

• DEVs agree to 
• use JSON for logs, 
• VRR as log retention strategy, 
• "imp" JSON field for VRR "importance" fields with values LOW, IMP, CRIT
• no "imp" field means LOW importance
• OPS agree to
• take this file and use retention and replication depending on those fields
• add "service" in filebeat for application name
• add "environment" in filebeat where applicable
• add "logschema":"vrr" to distinguish a common approach for logs.

As contract is mostly the same for all applications, Filebeat configuration is very reusable, one entry per application and box.

This file, in a working example, can be found here.

- type: log
  enabled: true <- important ;)
  paths:
    - /path/to/logFile.json 
  encoding: utf-8
  fields:
    logschema: vrr <- this value will be reused in Logstash configuration
    service: leveluplogging <- application / service name
    environment: production <- optional, very.

Next: 9 - VRR Logstash configuration and Index templates

Level up logs and ELK - VRR Logstash configuration

Articles index:

1. Introduction (Everyone)
2. JSON as logs format (Everyone)
3. Logging best practices with Logback (Targetting Java DEVs)
4. Logging cutting-edge practices (Targetting Java DEVs) 
5. Contract first log generator (Targetting Java DEVs)
6. ElasticSearch VRR Estimation Strategy (Targetting OPS)
7. VRR Java + Logback configuration (Targetting OPS)
8. VRR FileBeat configuration (Targetting OPS)
9. VRR Logstash configuration and Index templates (Targetting OPS)
10. VRR Curator configuration (Targetting OPS)
11. Logstash Grok, JSON Filter and JSON Input performance comparison (Targetting OPS)

VRR Logstash configuration and Index templates

Logstash configuration from example can be found here.

input {
  beats {
    port => 5044
    codec => json
  }
}

output {
     if [fields][logschema] == "vrr" { //for ALL VRR applications
        if [importance] == "CRIT" { //for ALL CRITICAL LINES
            elasticsearch { //send to SERVICE-LOGSCHEMA-IMP-DATE index (vrr-loggingup-crit-2018-09-10) with template template.max
                hosts => "localhost:9200"
                index => "vrr-%{[fields][service]}-crit-%{+YYYY-MM-dd}" //ONE INDEX PER APPLICATION AND DAY AND IMPORTANCE
                template => "/path/to/templates/template-max.json" //USING THIS TEMPLATE, NEXT CHAPTER!
                template_overwrite => true
                template_name => "vrr-max"
            }
        } else if [importance] == "IMP" { //for ALL CRITICAL LINES
            elasticsearch { //send to SERVICE-LOGSCHEMA-IMP-DATE index (vrr-loggingup-imp-2018-09-10) with template template.mid
                hosts => "localhost:9200"
                index => "vrr-%{[fields][service]}-imp-%{+YYYY-MM-dd}" //ONE INDEX PER APPLICATION AND DAY AND IMPORTANCE
                template => "/path/to/templates/template-mid.json" //USING THIS TEMPLATE, NEXT CHAPTER!
                template_overwrite => true
                template_name => "vrr-mid"
            }
        } else { //FOR BOTH "LOW" AND NO-EXPLICIT TAGGING
            elasticsearch { //send to SERVICE-LOGSCHEMA-IMP-DATE index (vrr-loggingup-low-2018-09-10) with template template.min
                hosts => "localhost:9200"
                index => "vrr-%{[fields][service]}-low-%{+YYYY-MM-dd}" //ONE INDEX PER APPLICATION AND DAY AND IMPORTANCE
                template => "/path/to/templates/template-min.json" //USING THIS TEMPLATE, NEXT CHAPTER!
                template_overwrite => true
                template_name => "vrr-min"
            }
        }
        
    } else { //OTHER NON-VRR APPLICATIONS
        elasticsearch {
            hosts => "localhost:9200"
            index => "logstash-classic-%{[fields][service]}-%{+YYYY-MM-dd-HH}" //STILL ONE SEPARATE INDEX PER APPLICATION AND DAY
        }
    }
}

Template template-max.json (here)

{

  "index_patterns": ["vrr-*-crit-*"], //FOR ALL INDICES THAT MATCH THIS EXPRESSION 

  "order" : 1, <- Overrides order 0 settings (default values like number of shards or mappings)

  "settings": {
    "number_of_replicas": 2 //WE WANT 2 EXTRA COPIES + MASTER
  }
}

Template template-mid.json (here)

{
  "index_patterns": ["vrr-*-imp-*"], //FOR ALL INDICES THAT MATCH THIS EXPRESSION 

  "order" : 1, <- Overrides order 0 settings (default values like number of shards or mappings)

  "settings": {
    "number_of_replicas": 1 //WE WANT AN EXTRA COPY + MASTER
  }
}

Template template-min.json (here)

{
  "index_patterns": ["vrr-*-low-*"], //FOR ALL INDICES THAT MATCH THIS EXPRESSION 

  "order" : 1, <- Overrides order 0 settings (default values like number of shards or mappings)

  "settings": {
    "number_of_replicas": 0 //WE DON'T WANT EXTRA COPIES, JUST MASTER
  }
}

Next: 10 - VRR Curator configuration