511 lines
20 KiB
Python
511 lines
20 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()
|