572 lines
21 KiB
Python
572 lines
21 KiB
Python
#!/usr/bin/env python
|
|
import base64
|
|
import requests
|
|
import gzip
|
|
import json
|
|
import msgpack
|
|
import struct
|
|
import os
|
|
import shutil
|
|
import re
|
|
import logging
|
|
import time
|
|
import io
|
|
import urllib
|
|
import datetime
|
|
import boto3
|
|
import botocore
|
|
|
|
__author__ = "Stefan Reimer"
|
|
__author_email__ = "stefan@zero-downtime.net"
|
|
__version__ = "0.9.10"
|
|
|
|
# IAM Alias lookup cache
|
|
account_aliases = {}
|
|
|
|
# ENI lookup cache
|
|
enis = {}
|
|
|
|
# IP lookup cache
|
|
ips = {}
|
|
|
|
logger = logging.getLogger(__name__)
|
|
logging.getLogger("urllib3").setLevel(logging.WARNING)
|
|
logging.getLogger("boto3").setLevel(logging.WARNING)
|
|
logging.getLogger("botocore").setLevel(logging.WARNING)
|
|
|
|
|
|
def boolean(value):
|
|
if value in ("t", "T", "true", "True", "TRUE", "1", 1, True):
|
|
return True
|
|
return False
|
|
|
|
|
|
def decrypt(encrypted):
|
|
try:
|
|
kms = boto3.client("kms")
|
|
plaintext = kms.decrypt(CiphertextBlob=base64.b64decode(encrypted))["Plaintext"]
|
|
return plaintext.decode()
|
|
except Exception:
|
|
logging.exception("Failed to decrypt via KMS")
|
|
|
|
|
|
CHUNK_SIZE = 128
|
|
DEBUG = boolean(os.getenv("DEBUG", default=False))
|
|
TEST = boolean(os.getenv("TEST", default=False))
|
|
RESOLVE_ACCOUNT = boolean(os.getenv("RESOLVE_ACCOUNT", default=True))
|
|
ENHANCE_FLOWLOG = boolean(os.getenv("ENHANCE_FLOWLOG", default=True))
|
|
|
|
if DEBUG:
|
|
logging.getLogger().setLevel(logging.DEBUG)
|
|
else:
|
|
logging.getLogger().setLevel(logging.INFO)
|
|
|
|
|
|
# From fluent/fluent-logger-python
|
|
class EventTime(msgpack.ExtType):
|
|
def __new__(cls, timestamp):
|
|
seconds = int(timestamp)
|
|
nanoseconds = int(timestamp % 1 * 10**9)
|
|
return super(EventTime, cls).__new__(
|
|
cls,
|
|
code=0,
|
|
data=struct.pack(">II", seconds, nanoseconds),
|
|
)
|
|
|
|
|
|
def fluentd_time(timestamp):
|
|
if isinstance(timestamp, float):
|
|
return EventTime(timestamp)
|
|
else:
|
|
return int(timestamp)
|
|
|
|
|
|
def get_source(region, account_id):
|
|
"""returns a new base source object
|
|
resolves aws account_id to account alias and caches for lifetime of lambda function
|
|
"""
|
|
global RESOLVE_ACCOUNT
|
|
source = {"account": account_id, "region": region}
|
|
if RESOLVE_ACCOUNT and not TEST:
|
|
try:
|
|
if account_id not in account_aliases:
|
|
boto3_config = botocore.config.Config(
|
|
retries=dict(max_attempts=2), connect_timeout=3, read_timeout=5
|
|
)
|
|
iam = boto3.client("iam", config=boto3_config)
|
|
account_aliases[account_id] = iam.list_account_aliases()[
|
|
"AccountAliases"
|
|
][0]
|
|
|
|
source["account_alias"] = account_aliases[account_id]
|
|
|
|
except (botocore.exceptions.ConnectTimeoutError, KeyError, IndexError):
|
|
logger.warning(
|
|
"Could not resolve IAM account alias, disabled for this session"
|
|
)
|
|
RESOLVE_ACCOUNT = False
|
|
pass
|
|
|
|
return source
|
|
|
|
|
|
def add_flow_metadata(flow):
|
|
"""adds metadata to VPC flow: ENI, direction, type
|
|
caches the ENI and IP lookup tables for Lambda lifetime
|
|
"""
|
|
global ENHANCE_FLOWLOG
|
|
if ENHANCE_FLOWLOG and not TEST:
|
|
try:
|
|
# Check cache and update if missed with all ENIs in one go
|
|
if flow["interface-id"] not in enis:
|
|
boto3_config = botocore.config.Config(
|
|
retries=dict(max_attempts=2), connect_timeout=3, read_timeout=5
|
|
)
|
|
ec2 = boto3.client("ec2", config=boto3_config)
|
|
interface_iter = ec2.get_paginator(
|
|
"describe_network_interfaces"
|
|
).paginate()
|
|
for response in interface_iter:
|
|
for interface in response["NetworkInterfaces"]:
|
|
# Lookup table by ENI ID
|
|
enis[interface["NetworkInterfaceId"]] = interface
|
|
|
|
# Lookup table by IP to classify traffic
|
|
ips[interface["PrivateIpAddress"]] = interface
|
|
except (botocore.exceptions.ConnectTimeoutError, KeyError, IndexError):
|
|
logger.warning(
|
|
"Error trying to get metadata for ENIs, disabling ENHANCE_FLOWLOG"
|
|
)
|
|
ENHANCE_FLOWLOG = False
|
|
return flow
|
|
|
|
try:
|
|
eni = enis[flow["interface-id"]]
|
|
metadata = {
|
|
"eni.az": eni["AvailabilityZone"],
|
|
"eni.subnet": eni["SubnetId"],
|
|
}
|
|
remote_ip = None
|
|
if len(eni["Groups"]):
|
|
metadata["eni.sg"] = eni["Groups"][0]["GroupName"]
|
|
|
|
# Add PublicIP if attached
|
|
if "Association" in eni and "PublicIp" in eni["Association"]:
|
|
metadata["eni.public_ip"] = eni["Association"]["PublicIp"]
|
|
|
|
# Determine traffic direction
|
|
if eni["PrivateIpAddress"] == flow["srcaddr"]:
|
|
metadata["direction"] = "Out"
|
|
remote_ip = flow["dstaddr"]
|
|
elif eni["PrivateIpAddress"] == flow["dstaddr"]:
|
|
metadata["direction"] = "In"
|
|
remote_ip = flow["srcaddr"]
|
|
|
|
# Try to classify traffic:
|
|
# Free,Regional,Out
|
|
if remote_ip:
|
|
if remote_ip in ips:
|
|
if (
|
|
ips[remote_ip]["AvailabilityZone"] == eni["AvailabilityZone"]
|
|
and ips[remote_ip]["VpcId"] == eni["VpcId"]
|
|
):
|
|
metadata["traffic_class"] = "Free"
|
|
else:
|
|
metadata["traffic_class"] = "Regional"
|
|
else:
|
|
# Incoming traffic is free 90% of times
|
|
if metadata["direction"] == "In":
|
|
metadata["traffic_class"] = "Free"
|
|
else:
|
|
metadata["traffic_class"] = "Out"
|
|
|
|
flow.update(metadata)
|
|
|
|
except (KeyError, IndexError) as e:
|
|
logger.warning(
|
|
"Could not get additional data for ENI {} ({})".format(
|
|
flow["interface-id"], e
|
|
)
|
|
)
|
|
pass
|
|
|
|
return flow
|
|
|
|
|
|
class Queue:
|
|
url = urllib.parse.urlsplit(os.getenv("FLUENTD_URL", default=""), scheme="https")
|
|
passwd = os.getenv("FLUENT_SHARED_KEY", default=None)
|
|
|
|
verify_certs = os.getenv("FLUENTD_VERIFY_CERTS", default=1)
|
|
if verify_certs in ("f", "F", "false", "False", "FALSE", "0", 0, False):
|
|
verify_certs = False
|
|
else:
|
|
verify_certs = True
|
|
|
|
# cached request session
|
|
request = requests.Session()
|
|
request.headers = {"Content-type": "application/msgpack"}
|
|
if passwd:
|
|
request.auth = ("fluent", passwd)
|
|
|
|
def __init__(self, tag):
|
|
self._queue = []
|
|
self.tag = tag
|
|
self.sent = 0
|
|
|
|
def send(self, event):
|
|
self._queue.append(event)
|
|
logger.debug("Queued {} event: {}".format(self.tag, event))
|
|
# Send events in chunks
|
|
if len(self._queue) >= CHUNK_SIZE:
|
|
self.flush()
|
|
|
|
def flush(self):
|
|
events = len(self._queue)
|
|
if not events:
|
|
return
|
|
|
|
logger.debug(
|
|
"Sending {} events to {}/{} ({})".format(
|
|
events, self.url.geturl(), self.tag, self.request
|
|
)
|
|
)
|
|
|
|
if not TEST:
|
|
# Send events via POSTs reusing the same https connection, retry couple of times
|
|
retries = 0
|
|
_url = "{}/{}".format(self.url.geturl(), self.tag)
|
|
while True:
|
|
try:
|
|
r = self.request.post(
|
|
url=_url,
|
|
data=msgpack.packb(self._queue),
|
|
verify=self.verify_certs,
|
|
timeout=(6, 30),
|
|
)
|
|
if r:
|
|
break
|
|
else:
|
|
logger.warning("HTTP Error: {}".format(r.status_code))
|
|
|
|
except requests.RequestException as e:
|
|
logger.warning("RequestException: {}".format(e))
|
|
pass
|
|
|
|
if retries >= 2:
|
|
raise Exception(
|
|
"Error sending {} events to {}. Giving up.".format(events, _url)
|
|
)
|
|
|
|
retries = retries + 1
|
|
time.sleep(1)
|
|
else:
|
|
logger.debug("Test mode, dump only: {}".format(msgpack.packb(self._queue)))
|
|
|
|
self.sent = self.sent + events
|
|
self._queue = []
|
|
|
|
def info(self):
|
|
logger.info(
|
|
"Sent {} events to {}/{} ({})".format(
|
|
self.sent, self.url.geturl(), self.tag, self.request
|
|
)
|
|
)
|
|
|
|
|
|
# Handler to handle CloudWatch logs.
|
|
def handler(event, context):
|
|
logger.debug("Event received: {}".format(event))
|
|
|
|
(region, account_id) = context.invoked_function_arn.split(":")[3:5]
|
|
|
|
# Cloudwatch Logs event
|
|
if "awslogs" in event:
|
|
# Grab the base64-encoded data.
|
|
b64strg = event["awslogs"]["data"]
|
|
|
|
# Decode base64-encoded string, which should be a gzipped object.
|
|
zippedContent = io.BytesIO(base64.b64decode(b64strg))
|
|
|
|
# Decompress the content and load JSON.
|
|
with gzip.GzipFile(mode="rb", fileobj=zippedContent) as content:
|
|
for line in content:
|
|
awsLogsData = json.loads(line.decode())
|
|
|
|
# First determine type
|
|
if re.match("/aws/lambda/", awsLogsData["logGroup"]):
|
|
logs = Queue("aws.lambda")
|
|
elif re.search("cloudtrail", awsLogsData["logGroup"], flags=re.IGNORECASE):
|
|
logs = Queue("aws.cloudtrail")
|
|
elif re.match("RDSOSMetrics", awsLogsData["logGroup"]):
|
|
logs = Queue("aws.rdsosmetrics")
|
|
elif re.match("vpcflowlog", awsLogsData["logGroup"], flags=re.IGNORECASE):
|
|
logs = Queue("aws.vpcflowlog")
|
|
else:
|
|
logs = Queue("aws.cloudwatch_logs")
|
|
|
|
# Build list of log events
|
|
for e in awsLogsData["logEvents"]:
|
|
event = {}
|
|
source = get_source(region, account_id)
|
|
parsed = {}
|
|
|
|
# Remove whitespace / empty events & skip over empty events
|
|
e["message"] = e["message"].strip()
|
|
if re.match(r"^\s*$", e["message"]):
|
|
continue
|
|
|
|
# inject existing data from subscrition filters
|
|
if "extractedFields" in e.keys():
|
|
for key in e["extractedFields"]:
|
|
event[key] = e["extractedFields"][key]
|
|
|
|
# lambda ?
|
|
if logs.tag == "aws.lambda":
|
|
# First look for the three AWS Lambda entries
|
|
mg = re.match(
|
|
r"(?P<type>(START|END|REPORT)) RequestId: (?P<request>\S*)",
|
|
e["message"],
|
|
)
|
|
if mg:
|
|
parsed["RequestId"] = mg.group("request")
|
|
if mg.group("type") == "REPORT":
|
|
pattern = r".*(?:\tDuration: (?P<duration>[\d\.\d]+) ms\s*)(?:\tBilled Duration: (?P<billed_duration>[\d\.\d]+) ms\s*)(?:\tMemory Size: (?P<memory_size>[\d\.\d]+) MB\s*)(?:\tMax Memory Used: (?P<max_memory_used>[\d\.\d]+) MB)(?:\tInit Duration: (?P<init_duration>[\d\.\d]+) ms\s*)?"
|
|
|
|
elif mg.group("type") == "START":
|
|
pattern = r".*(?:Version: (?P<version>.*))"
|
|
|
|
else:
|
|
pattern = ""
|
|
|
|
data = re.match(pattern, e["message"])
|
|
for key in data.groupdict().keys():
|
|
if data.group(key):
|
|
parsed[key] = data.group(key)
|
|
|
|
# All other info parsed, so just set type itself
|
|
event["message"] = mg.group("type")
|
|
|
|
else:
|
|
# Try to extract data from AWS default python logging format
|
|
# This normalizes print vs. logging entries and allows requestid tracking
|
|
# "[%(levelname)s]\t%(asctime)s.%(msecs)dZ\t%(aws_request_id)s\t%(message)s\n"
|
|
_msg = e["message"]
|
|
pattern = r"(?:\[(?P<level>[^\]]*)\]\s)?(?P<time>\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{1,6}Z)\s(?P<RequestId>\S*?)\s(?P<message>.*)"
|
|
data = re.match(pattern, e["message"], flags=re.DOTALL)
|
|
if data:
|
|
if data.group("level"):
|
|
event["level"] = data.group("level")
|
|
event["time"] = fluentd_time(
|
|
datetime.datetime.strptime(
|
|
data.group("time"), "%Y-%m-%dT%H:%M:%S.%fZ"
|
|
).timestamp()
|
|
)
|
|
parsed["RequestId"] = data.group("RequestId")
|
|
_msg = data.group("message")
|
|
|
|
# try to parse the remaining as json
|
|
try:
|
|
_json = json.loads(_msg)
|
|
# Make sure we have an actual object assigned to json field
|
|
if isinstance(_json, dict):
|
|
event["message_json"] = _json
|
|
else:
|
|
event["message"] = _json
|
|
except (ValueError, TypeError, KeyError):
|
|
event["message"] = _msg
|
|
|
|
# cloudtrail ?
|
|
elif logs.tag == "aws.cloudtrail":
|
|
try:
|
|
parsed = json.loads(e["message"])
|
|
|
|
# use eventTime and eventID from the event itself
|
|
event["time"] = fluentd_time(
|
|
datetime.datetime.strptime(
|
|
parsed["eventTime"], "%Y-%m-%dT%H:%M:%SZ"
|
|
).timestamp()
|
|
)
|
|
event["id"] = parsed["eventID"]
|
|
# override region from cloudtrail event
|
|
source["region"] = parsed["awsRegion"]
|
|
|
|
except (ValueError, TypeError, KeyError):
|
|
event["message"] = e["message"]
|
|
parsed.clear()
|
|
|
|
# RDS metrics ?
|
|
elif logs.tag == "aws.rdsosmetrics":
|
|
try:
|
|
parsed = json.loads(e["message"])
|
|
|
|
except (ValueError, TypeError, KeyError):
|
|
event["message"] = e["message"]
|
|
|
|
# VPC FlowLog ?
|
|
# <version> <account-id> <interface-id> <srcaddr> <dstaddr> <srcport> <dstport> <protocol> <packets> <bytes> <start> <end> <action> <log-status>
|
|
elif logs.tag == "aws.vpcflowlog":
|
|
row = e["message"].split(" ")
|
|
|
|
# Skip over NODATA,SKIPDATA entries, what would be the point having these in ES ?
|
|
if row[13] != "OK":
|
|
continue
|
|
|
|
parsed = add_flow_metadata(
|
|
{
|
|
"interface-id": row[2],
|
|
"srcaddr": row[3],
|
|
"dstaddr": row[4],
|
|
"srcport": row[5],
|
|
"dstport": row[6],
|
|
"protocol": row[7],
|
|
"packets": row[8],
|
|
"bytes": row[9],
|
|
"start": row[10],
|
|
"end": row[11],
|
|
"action": row[12],
|
|
"log-status": row[13],
|
|
}
|
|
)
|
|
|
|
# Fallback add raw message
|
|
else:
|
|
event["message"] = e["message"]
|
|
|
|
if parsed and logs.tag:
|
|
event[logs.tag] = parsed
|
|
|
|
# Forward cloudwatch logs event ID
|
|
source["log_group"] = awsLogsData["logGroup"]
|
|
source["log_stream"] = awsLogsData["logStream"]
|
|
event["source"] = source
|
|
|
|
# If time and id are not set yet use data from cloudwatch logs event
|
|
if "time" not in event:
|
|
event["time"] = fluentd_time(e["timestamp"] / 1000)
|
|
if "id" not in source:
|
|
event["id"] = e["id"]
|
|
|
|
logs.send(event)
|
|
|
|
logs.flush()
|
|
logs.info()
|
|
|
|
# S3 Put event
|
|
elif "Records" in event:
|
|
s3_client = boto3.client("s3")
|
|
|
|
bucket = event["Records"][0]["s3"]["bucket"]["name"]
|
|
key = event["Records"][0]["s3"]["object"]["key"]
|
|
|
|
file_path = "/tmp/stream2fluentd.gz"
|
|
if TEST:
|
|
shutil.copyfile(key, file_path)
|
|
else:
|
|
s3_client.download_file(bucket, key, file_path)
|
|
source = get_source(region, account_id)
|
|
source["s3_url"] = "{}/{}".format(bucket, key)
|
|
|
|
alb_regex = re.compile(
|
|
r"(?P<type>[^ ]*) (?P<timestamp>[^ ]*) (?P<elb>[^ ]*) (?P<client_ip>[^ ]*):(?P<client_port>[0-9]*) (?P<target_ip>[^ ]*)[:-](?P<target_port>[0-9]*) (?P<request_processing_time>[-.0-9]*) (?P<target_processing_time>[-.0-9]*) (?P<response_processing_time>[-.0-9]*) (?P<elb_status_code>|[-0-9]*) (?P<target_status_code>-|[-0-9]*) (?P<received_bytes>[-0-9]*) (?P<sent_bytes>[-0-9]*) \"(?P<request_verb>[^ ]*) (?P<request_url>[^\"]*) (?P<request_proto>- |[^ ]*)\" \"(?P<user_agent>[^\"]*)\" (?P<ssl_cipher>[A-Z0-9-]+) (?P<ssl_protocol>[A-Za-z0-9.-]*) (?P<target_group_arn>[^ ]*) \"(?P<trace_id>[^\"]*)\" \"(?P<domain_name>[^\"]*)\" \"(?P<chosen_cert_arn>[^\"]*)\" (?P<matched_rule_priority>[-.0-9]*) (?P<request_creation_time>[^ ]*) \"(?P<actions_executed>[^\"]*)\" \"(?P<redirect_url>[^ ]*)\" \"(?P<error_reason>[^ ]*)\""
|
|
)
|
|
|
|
# try to identify file type by looking at first lines
|
|
with gzip.open(file_path, mode="rt", newline="\n") as data:
|
|
header = data.readlines(2048)
|
|
|
|
# ALB Access ?
|
|
if alb_regex.match(header[0]):
|
|
logs = Queue("aws.alb_accesslog")
|
|
|
|
# cloudfront access logs
|
|
elif (
|
|
len(header) > 1
|
|
and re.match("#Version:", header[0])
|
|
and re.match("#Fields:", header[1])
|
|
):
|
|
logs = Queue("aws.cloudfront_accesslog")
|
|
|
|
else:
|
|
logger.warning("{}/{}: Unknown type!".format(bucket, key))
|
|
return
|
|
|
|
if logs.tag == "aws.alb_accesslog":
|
|
with gzip.open(file_path, mode="rt", newline="\n") as data:
|
|
for line in data:
|
|
event = {}
|
|
parsed = {}
|
|
data = alb_regex.match(line)
|
|
if data:
|
|
for key in data.groupdict().keys():
|
|
value = data.group(key)
|
|
|
|
# Remove empty values
|
|
if value in ["-", "-\n"]:
|
|
continue
|
|
|
|
# Remove times of requests timed out
|
|
if key in [
|
|
"request_processing_time",
|
|
"target_processing_time",
|
|
"response_processing_time",
|
|
] and value in ["-1"]:
|
|
continue
|
|
|
|
parsed[key] = data.group(key)
|
|
else:
|
|
logger.warning(
|
|
"Could not parse ALB access log entry: {}".format(line)
|
|
)
|
|
continue
|
|
|
|
event["time"] = fluentd_time(
|
|
datetime.datetime.strptime(
|
|
parsed["request_creation_time"], "%Y-%m-%dT%H:%M:%S.%fZ"
|
|
).timestamp()
|
|
)
|
|
|
|
# Copy to host to allow geoip upstream
|
|
event["host"] = parsed["client_ip"]
|
|
event[logs.tag] = parsed
|
|
event["source"] = source
|
|
|
|
logs.send(event)
|
|
|
|
elif logs.tag == "aws.cloudfront_accesslog":
|
|
with gzip.open(file_path, mode="rt", newline="\n") as data:
|
|
next(data)
|
|
# columns are in second line: first is #Fields, next two are merged into time later
|
|
columns = next(data).split()[3:]
|
|
|
|
for line in data:
|
|
event = {}
|
|
parsed = {}
|
|
|
|
# Todo hash each line to create source['id']
|
|
# source['id'] = md5.of.line matching ES ids
|
|
|
|
row = line.split("\t")
|
|
# cloudfront events are logged to the second only, date and time are seperate
|
|
event["time"] = fluentd_time(
|
|
datetime.datetime.strptime(
|
|
row[0] + " " + row[1], "%Y-%m-%d %H:%M:%S"
|
|
).timestamp()
|
|
)
|
|
|
|
for n, c in enumerate(columns, 2):
|
|
value = row[n]
|
|
if value not in ["-", "-\n"]:
|
|
parsed[c] = row[n]
|
|
# Copy c-ip to host to allow geoip upstream
|
|
if c == "c-ip":
|
|
event["host"] = row[n]
|
|
|
|
event[logs.tag] = parsed
|
|
event["source"] = source
|
|
|
|
logs.send(event)
|
|
|
|
logs.flush()
|
|
logs.info()
|