Skip to content

Commit

Permalink
[LOGGER]: Initial Jac-Cloud logger handler
Browse files Browse the repository at this point in the history
  • Loading branch information
amadolid committed Oct 4, 2024
1 parent 7cacfb9 commit ed1e7a3
Show file tree
Hide file tree
Showing 9 changed files with 312 additions and 15 deletions.
4 changes: 4 additions & 0 deletions jac-cloud/.gitignore
Original file line number Diff line number Diff line change
Expand Up @@ -51,3 +51,7 @@ out.txt
# Mypy files #
.mypy_cache*
.jac_mypy_cache


# Jac-Cloud #
logs/
25 changes: 25 additions & 0 deletions jac-cloud/filebeat.yml
Original file line number Diff line number Diff line change
@@ -0,0 +1,25 @@
# =============================== Elastic Cloud ================================

filebeat.inputs:

# Each - is an input. Most options can be set at the input level, so
# you can use different inputs for various configurations.
# Below are the input specific configurations.

- type: log

# Change to true to enable this input configuration.
enabled: true

# Paths that should be crawled and fetched. Glob based paths.
paths:
- /path/to/logs/jac-cloud.json

output.elasticsearch:
hosts: ["localhost:9200"]
protocol: https
api_key: "id:api_key"
index: "filebeat-testing"

setup.template.name: "filebeat"
setup.template.pattern: "filebeat-*"
5 changes: 2 additions & 3 deletions jac-cloud/jac_cloud/core/context.py
Original file line number Diff line number Diff line change
Expand Up @@ -8,7 +8,6 @@
from bson import ObjectId

from fastapi import Request
from fastapi.responses import ORJSONResponse

from jaclang.runtimelib.context import ExecutionContext

Expand Down Expand Up @@ -144,7 +143,7 @@ def get_root() -> Root: # type: ignore[override]
"""Get current root."""
return cast(Root, JaseciContext.get().root.architype)

def response(self, returns: list[Any]) -> ORJSONResponse:
def response(self, returns: list[Any]) -> dict[str, Any]:
"""Return serialized version of reports."""
resp = ContextResponse[Any](status=self.status)

Expand All @@ -159,7 +158,7 @@ def response(self, returns: list[Any]) -> ORJSONResponse:
if SHOW_ENDPOINT_RETURNS:
resp.returns = returns

return ORJSONResponse(resp.__serialize__(), status_code=self.status)
return resp.__serialize__()

def clean_response(
self, key: str | int, val: Any, obj: list | dict # noqa: ANN401
Expand Down
6 changes: 6 additions & 0 deletions jac-cloud/jac_cloud/jaseci/models/user.py
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,12 @@ def obfuscate(self) -> dict:
data["password"] = pbkdf2_sha512.hash(self.password).encode()
return data

def printable(self) -> dict:
"""Return BaseModel.model_dump where the password is hashed."""
data = self.model_dump(exclude={"password"})
data["password"] = "****"
return data


@dataclass(kw_only=True)
class User:
Expand Down
13 changes: 10 additions & 3 deletions jac-cloud/jac_cloud/jaseci/routers/user.py
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@
invalidate_token,
verify_code,
)
from ..utils import Emailer, logger
from ..utils import Emailer, log_entry, log_exit, logger
from ...core.architype import BulkWrite, NodeAnchor, Root


Expand All @@ -38,6 +38,8 @@
@router.post("/register", status_code=status.HTTP_200_OK)
def register(req: User.register_type()) -> ORJSONResponse: # type: ignore
"""Register user API."""
log = log_entry("register", req.email, req.printable())

with User.Collection.get_session() as session, session.start_transaction():
root = Root().__jac__

Expand All @@ -56,7 +58,9 @@ def register(req: User.register_type()) -> ORJSONResponse: # type: ignore
BulkWrite.commit(session)
if not is_activated:
User.send_verification_code(create_code(id), req.email)
return ORJSONResponse({"message": "Successfully Registered!"}, 201)
resp = {"message": "Successfully Registered!"}
log_exit(resp, log)
return ORJSONResponse(resp, 201)
except (ConnectionFailure, OperationFailure) as ex:
if ex.has_error_label("TransientTransactionError"):
retry += 1
Expand All @@ -72,7 +76,10 @@ def register(req: User.register_type()) -> ORJSONResponse: # type: ignore
logger.exception("Error executing bulk write!")
session.abort_transaction()
break
return ORJSONResponse({"message": "Registration Failed!"}, 409)

resp = {"message": "Registration Failed!"}
log_exit(resp, log)
return ORJSONResponse(resp, 409)


@router.post(
Expand Down
7 changes: 3 additions & 4 deletions jac-cloud/jac_cloud/jaseci/utils/__init__.py
Original file line number Diff line number Diff line change
@@ -1,10 +1,10 @@
"""Jaseci Utilities."""

import logging
from datetime import datetime, timedelta, timezone
from random import choice
from string import ascii_letters, digits

from .logger import log_entry, log_exit, logger
from .mail import Emailer, SendGridEmailer


Expand All @@ -23,14 +23,13 @@ def utc_timestamp(**addons: int) -> int:
return int(utc_datetime(**addons).timestamp())


logger = logging.getLogger(__name__)
# logger.addHandler(logging.StreamHandler(sys.stdout))

__all__ = [
"Emailer",
"SendGridEmailer",
"random_string",
"utc_datetime",
"utc_timestamp",
"log_entry",
"log_exit",
"logger",
]
242 changes: 242 additions & 0 deletions jac-cloud/jac_cloud/jaseci/utils/logger.py
Original file line number Diff line number Diff line change
@@ -0,0 +1,242 @@
"""Jaseci Log Handlers."""

from datetime import time as dtime
from enum import IntEnum
from io import text_encoding
from logging import FileHandler, LogRecord, getLogger
from logging.handlers import (
BaseRotatingHandler,
RotatingFileHandler,
TimedRotatingFileHandler,
)
from os import getenv, remove, rename, stat
from os.path import exists, isfile
from pathlib import Path
from re import ASCII, compile
from stat import ST_MTIME
from time import gmtime, localtime, strftime, time as ttime
from typing import Any

from ecs_logging import StdlibFormatter


class MixedTimedRotatingFileHandler(TimedRotatingFileHandler, RotatingFileHandler):
"""Merge TimedRotatingFileHandler and RotatingFileHandler."""

# mypy bug: Incompatible types in assignment
# (expression has type "int", base class "RotatingFileHandler" defined the type as "str")
# even RotatingHandler declared as int
maxBytes: int # type: ignore[assignment] # noqa: N815

def __init__(
self,
filename: str,
when: str = "h",
interval: int = 1,
max_bytes: int = 0,
backup_count: int = 0,
encoding: str | None = None,
delay: bool = False,
utc: bool = False,
at_time: dtime | None = None,
errors: str | None = None,
) -> None:
"""Override __init__."""
encoding = text_encoding(encoding)
BaseRotatingHandler.__init__(
self, filename, "a", encoding=encoding, delay=delay, errors=errors
)

file_path = Path(self.baseFilename)
self.file_folder = file_path.parent.absolute()
self.file_name = file_path.stem
self.file_ext = file_path.suffix

self.maxBytes: int = max_bytes
self.when = when.upper()
self.backupCount = backup_count
self.utc = utc
self.atTime = at_time
if self.when == "S":
self.interval = 1
self.suffix = "%Y-%m-%d-%H-%M-%S"
ext_match = r"(?<!\d)\d{4}-\d{2}-\d{2}_\d{2}-\d{2}-\d{2}(?!\d)"
elif self.when == "M":
self.interval = 60
self.suffix = "%Y-%m-%d-%H-%M"
ext_match = r"(?<!\d)\d{4}-\d{2}-\d{2}_\d{2}-\d{2}(?!\d)"
elif self.when == "H":
self.interval = 60 * 60
self.suffix = "%Y-%m-%d-%H"
ext_match = r"(?<!\d)\d{4}-\d{2}-\d{2}_\d{2}(?!\d)"
elif self.when == "D" or self.when == "MIDNIGHT":
self.interval = 60 * 60 * 24
self.suffix = "%Y-%m-%d"
ext_match = r"(?<!\d)\d{4}-\d{2}-\d{2}(?!\d)"
elif self.when.startswith("W"):
self.interval = 60 * 60 * 24 * 7
if len(self.when) != 2:
raise ValueError(
f"You must specify a day for weekly rollover from 0 to 6 (0 is Monday): {self.when}"
)
if self.when[1] < "0" or self.when[1] > "6":
raise ValueError(
f"Invalid day specified for weekly rollover: {self.when}"
)
self.dayOfWeek = int(self.when[1])
self.suffix = "%Y-%m-%d"
ext_match = r"(?<!\d)\d{4}-\d{2}-\d{2}(?!\d)"
else:
raise ValueError(f"Invalid rollover interval specified: {self.when}")

self.extMatch = compile(ext_match, ASCII)
self.interval = self.interval * interval
filename = self.baseFilename
if exists(filename):
t = stat(filename)[ST_MTIME]
else:
t = ttime()
self.rolloverAt = self.computeRollover(int(t))

def build_file_name(self, prefix: str, part: int) -> str:
"""Override rotation_filename."""
name = f"{self.file_folder}/{prefix}-{self.file_name}-{part}{self.file_ext}"

if not callable(self.namer):
return name
else:
return self.namer(name)

def doRollover(self) -> None: # noqa: N802
"""Override doRollover."""
current_time = int(ttime())
t = self.rolloverAt - self.interval
if self.utc:
time_tuple = gmtime(t)
else:
time_tuple = localtime(t)
dst_now = localtime(current_time)[-1]
dst_then = time_tuple[-1]
if dst_now != dst_then:
if dst_now:
addend = 3600
else:
addend = -3600
time_tuple = localtime(t + addend)
prefix = strftime(self.suffix, time_tuple)

if self.stream:
self.stream.close()
self.stream = None # type: ignore[assignment]
if self.backupCount > 0:
for i in range(self.backupCount - 1, 0, -1):
sfn = self.build_file_name(prefix, i)
dfn = self.build_file_name(prefix, i + 1)
if exists(sfn):
if exists(dfn):
remove(dfn)
rename(sfn, dfn)
dfn = self.build_file_name(prefix, 1)
if exists(dfn):
remove(dfn)
self.rotate(self.baseFilename, dfn)
else:
part = 1
while True:
dfn = self.build_file_name(prefix, part)
if not exists(dfn):
self.rotate(self.baseFilename, dfn)
break
part += 1

if not self.delay:
self.stream = self._open()

def shouldRollover(self, record: LogRecord) -> bool: # noqa: N802
"""Override shouldRollover."""
t = int(ttime())
if exists(self.baseFilename) and not isfile(self.baseFilename):
self.rolloverAt = self.computeRollover(t)
return False
if self.stream is None:
self.stream = self._open()
if self.maxBytes > 0:
msg = "%s\n" % self.format(record)
self.stream.seek(0, 2)
if self.stream.tell() + len(msg) >= self.maxBytes:
return True
if t >= self.rolloverAt:
self.rolloverAt = self.computeRollover(t)
return True
return False


class Level(IntEnum):
"""Log Level Enum."""

CRITICAL = 50
FATAL = CRITICAL
ERROR = 40
WARNING = 30
WARN = WARNING
INFO = 20
DEBUG = 10
NOTSET = 0


logger = getLogger(getenv("LOGGER_NAME", "app"))
logger.setLevel(Level[getenv("LOGGER_LEVEL", "DEBUG")].value)

if getenv("ELASTIC_LOGGER") == "true":
handler = FileHandler(getenv("LOGGER_FILE_PATH", "elastic-log.json"))
handler.setFormatter(StdlibFormatter())
logger.addHandler(handler)
else:
handler = MixedTimedRotatingFileHandler(
getenv("LOGGER_FILE_PATH", "jac-cloud.log"),
when="d",
backup_count=int(getenv("LOGGER_DAILY_MAX_FILE", "-1")),
max_bytes=int(getenv("LOGGER_MAX_FILE_SIZE", "10000000")),
)
handler.setFormatter(StdlibFormatter())
logger.addHandler(handler)


def log_entry(
api: str, caller: str | None, payload: dict[str, Any], node: str | None = None
) -> dict[str, Any]:
"""Log metadata on entry."""
log: dict[str, Any] = {
"api_name": api,
"caller_name": caller,
"payload": payload,
"entry_node": node,
}
msg = str(
f"Incoming call from {log["caller_name"]}"
f" to {log["api_name"]}"
f" with payload: {log["payload"]}"
f" at entry node: {log["entry_node"]}"
)
log["extra_fields"] = list(log.keys())
logger.info(msg, extra=log)

return log


def log_exit(response: dict[str, Any], log: dict[str, Any] | None = None) -> None:
"""Log metadata on exit."""
log = log or {}
log["api_response"] = response
log["extra_fields"] = list(log.keys())
log_msg = str(
f"Returning call from {log["caller_name"]}"
f" to {log["api_name"]}"
f" with payload: {log["payload"]}"
f" at entry node: {log["entry_node"]}"
f" with response: {log["api_response"]}"
)
logger.info(
log_msg,
extra=log,
)
Loading

0 comments on commit ed1e7a3

Please sign in to comment.