Leveraging Log Streaming to Build the Best Dashboards, Ever

{{- $logtype := env "CDN_LOG_TYPE" -}}
 
input {
  tcp {
    host => "0.0.0.0"
    codec => {{ if eq $logtype "metrics" }} plain {{ else }} json {{ end }}
    port => 514
    type => "cdn-{{ $logtype }}"
    tags => ["cdn","{{ $logtype }}"]
  }
}
 
output {
  if "cdn" in [tags] {
    kafka {
      bootstrap_servers => "kafka-broker.internal:9092"
      acks => "0"
      {{ if eq $logtype "metrics" }}
      topic_id => "cdn-metrics"
      codec => plain {
         format => "%{message}"
      }
      {{ else }}
      topic_id => "cdn-logs"
      {%raw%}{{ end }}
    }
  }
}

sub vcl_log {
  if (resp.status >= 400) {
    log {"syslog $SERVICE_ID DEST-APP :: "}
    {"{"}
    {" "product":"api", "}
    {" "x-api-id":""} req.http.X-API-ID {"", "}
    {" "api_name":""} req.http.API-Name {"", "}
    {" "request_url":""} req.url {"", "}
    {" "req_body_read":"} req.bytes_read {", "}
    {" "resp_body_written":"} resp.bytes_written {", "}
    {" "request_backend":""} req.http.Request-Backend {"", "}
    {" "actual_backend_name":""} req.http.Actual-Backend-Name {"", "}
    {" "actual_backend_ip":""} req.http.Actual-Backend-IP {"", "}
    {" "client_ip":""} client.ip {"", "}
    {" "event_timestamp":""} strftime({"%Y-%m-%dT%H:%M:%SZ"}, now) {"", "}
    {" "method":""} req.request {"", "}
    {" "resp_status":""} resp.status {"", "}
    {" "resp_message":""} resp.response {"", "}
    {" "cache_status":""} resp.http.X-Cache {"", "}
    {" "elapsed_time":"} time.elapsed.msec {", "}
    {" "fastly_info_state":""} fastly_info.state {"", "}
    {" "fastly_pop":""} server.datacenter {"", "}
    {" "fastly_region":""} server.region {"", "}
    {" "fastly_server":""} server.identity {"", "}
    {" "scheme_type":""} req.http.SchemeType {"""}
    {"}"};
  }  
}

• We only log if the status code is 400 or above. This goes back to only keeping the errors.
• This is a structured JSON message, encoded in VCL. These two things don't always get along well, but by taking advantage of the fact that VCL doesn't care about line breaks, we can use them to construct what will ultimately be a single line of JSON in many lines of VCL. Neato. A word of warning - the quotes and braces get confusing, so the best bet is to leave your last line alone, and only add above it. Feel free to take mine above as a starting point - it's valid, I promise.
• There are a handful of variables in there that we parse out of the URL in VCL using regular expressions. These variables are useful to us in many other ways, and logging is just one of them. For example, req.http.API-Name represents which API is going through our API service, and req.http.Request-Backend is the name of the data center we intended to send the request to, where req.http.Actual-Backend-Name is the name of the individual data center it did go to. Since we use directors, these values could differ. Likewise, if Fastly has trouble talking to our backends, the actual backend will be null.

• Measurement - The grouping of data you're collecting, akin to a database table.
• Tag - An attribute of the measurement in key/value format. Tags are always strings.
• Field - The actual measurement value in the form of an int, float, string or bool.
• Timestamp - When the measurement occurred. This can be in different forms, but nanosecond-prevision is preferred.

log {"syslog $SERVICE-ID DEST-METRICS :: "}
 {"cdnmetrics,"}
 {"product=api,"}
 {"environment=prod,"}
 {"cache_status="} resp.http.X-Cache {","}
 {"resp_status="} resp.status {","}
 {"api_name="} req.http.API-Name {","}
 {"request_backend="} req.http.Request-Backend {","}
 {"actual_backend="} req.http.Actual-Backend-Name {","}
 {"info_state="} fastly_info.state {","}
 {"pop="} server.datacenter {","}
 {"region="} server.region
 {" "}
 {"elapsed_time="} time.elapsed.msec {","}
 {"time_to_first_byte="} time.to_first_byte
 {" "}
 time.end.usec {"000"};

• The two empty spaces are critical to ILP - it's how it distinguishes tags from fields and fields from the timestamp. Since multiline VCL like this comes across as a single line, having those spaces on their own makes it easy to read.
• Similarly, any key/value pair that may have a space needs quotes, and they need to be double quotes. Don't forget that VCL doesn#39;t require escaping them, but it will get confusing to read.
• There are many variables in this entry that are parsed similarly to the ones in our log entry. Pull useful data about your configuration into variables for consumption here. Adding them as request headers is a good way to make sure they don't get returned to the consumer, but they will end up on your origin.

cdnmetrics,product=api,environment=prod,cache_status=HIT,resp_status=200,api_name=locations-v2,request_backend=director_Target,actual_backend=$SERVICEID—TargetBackend1,info_state=HIT,pop=MD,region=US-Central elapsed_time=0,time_to_first_byte=0.000 1522670899146991000

cdnmetrics,
product=api,
environment=prod,
cache_status=HIT,
resp_status=200,
api_name=locations-v2,
request_backend=director_Target,
actual_backend=$SERVICEID—TargetBackend1,
info_state=HIT,
pop=MDW,
region=US-Central
 
elapsed_time=0,
time_to_first_byte=0.000
 
1522670899146991000