From 8e785c18301773a67f74bd021f584701856da4aa Mon Sep 17 00:00:00 2001 From: Colton Myers Date: Wed, 18 Sep 2019 14:52:22 -0600 Subject: [PATCH 1/5] Add logging Formatter class We need a custom Formatter class in order to add error handling for any logs which happen before the Client is initialized (and our LogRecordFactory is put into place). --- docs/logging.asciidoc | 28 +++++++++++------ elasticapm/handlers/logging.py | 40 +++++++++++++++++++++++++ tests/handlers/logging/logging_tests.py | 14 ++++++++- 3 files changed, 72 insertions(+), 10 deletions(-) diff --git a/docs/logging.asciidoc b/docs/logging.asciidoc index 6f972fd03..4df9a916a 100644 --- a/docs/logging.asciidoc +++ b/docs/logging.asciidoc @@ -96,23 +96,33 @@ that looks like this: ---- import logging +fh = logging.FileHandler('spam.log') formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s") +fh.setFormatter(formatter) ---- -You can add the APM identifiers in an easy-to-parse manner: +You can add the APM identifiers by simply switching out the `Formatter` object +for the one that we provide: [source,python] ---- import logging +from elasticapm.handlers.logging import Formatter -format_string = ( - "%(asctime)s - %(name)s - %(levelname)s - %(message)s " - "| elasticapm " - "transaction.id=%(elasticapm_transaction_id) " - "trace.id=%(elasticapm_trace_id) " - "span.id=%(elasticapm_span_id)" -) -formatter = logging.Formatter(format_string) +fh = logging.FileHandler('spam.log') +formatter = Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s") +fh.setFormatter(formatter) +---- + +This will automatically append apm-specific fields to your format string: + +[source,python] +---- +formatstring = "%(asctime)s - %(name)s - %(levelname)s - %(message)s" +formatstring = formatstring + "| elasticapm " \ + "transaction.id=%(elasticapm_transaction_id)s " \ + "trace.id=%(elasticapm_trace_id)s " \ + "span.id=%(elasticapm_span_id)s" ---- Then, you could use a grok pattern like this (for the diff --git a/elasticapm/handlers/logging.py b/elasticapm/handlers/logging.py index 3adf92807..a2db177fc 100644 --- a/elasticapm/handlers/logging.py +++ b/elasticapm/handlers/logging.py @@ -223,3 +223,43 @@ def _add_attributes_to_log_record(record): record.elasticapm_labels = {"transaction.id": transaction_id, "trace.id": trace_id, "span.id": span_id} return record + + +class Formatter(logging.Formatter): + """ + Custom formatter to automatically append the elasticapm format string, + as well as ensure that LogRecord objects actually have the required fields + (so as to avoid errors which could occur for logs before we override the + LogRecordFactory): + + formatstring = "%(asctime)s - %(name)s - %(levelname)s - %(message)s" + formatstring = formatstring + "| elasticapm " \ + "transaction.id=%(elasticapm_transaction_id)s " \ + "trace.id=%(elasticapm_trace_id)s " \ + "span.id=%(elasticapm_span_id)s" + """ + + def __init__(self, fmt=None, datefmt=None, style="%"): + if fmt is None: + fmt = "%(message)s" + fmt = ( + fmt + "| elasticapm " + "transaction.id=%(elasticapm_transaction_id)s " + "trace.id=%(elasticapm_trace_id)s " + "span.id=%(elasticapm_span_id)s" + ) + super(Formatter, self).__init__(fmt=fmt, datefmt=datefmt, style=style) + + def format(self, record): + if not hasattr(record, "elasticapm_transaction_id"): + record.elasticapm_transaction_id = None + record.elasticapm_trace_id = None + record.elasticapm_span_id = None + return super(Formatter, self).format(record=record) + + def formatTime(self, record, datefmt=None): + if not hasattr(record, "elasticapm_transaction_id"): + record.elasticapm_transaction_id = None + record.elasticapm_trace_id = None + record.elasticapm_span_id = None + return super(Formatter, self).formatTime(record=record, datefmt=datefmt) diff --git a/tests/handlers/logging/logging_tests.py b/tests/handlers/logging/logging_tests.py index b9c102e5c..3a477a32f 100644 --- a/tests/handlers/logging/logging_tests.py +++ b/tests/handlers/logging/logging_tests.py @@ -36,7 +36,7 @@ from elasticapm.conf import Config from elasticapm.conf.constants import ERROR -from elasticapm.handlers.logging import LoggingFilter, LoggingHandler, log_record_factory +from elasticapm.handlers.logging import Formatter, LoggingFilter, LoggingHandler, log_record_factory from elasticapm.handlers.structlog import structlog_processor from elasticapm.traces import Tracer, capture_span, execution_context from elasticapm.utils import compat @@ -313,3 +313,15 @@ def test_automatic_log_record_factory_install(elasticapm_client): assert record.elasticapm_trace_id == transaction.trace_parent.trace_id assert record.elasticapm_span_id == span.id assert record.elasticapm_labels + + +def test_formatter(): + record = logging.LogRecord(__name__, logging.DEBUG, __file__, 252, "dummy_msg", [], None) + formatter = Formatter() + formatted_record = formatter.format(record) + assert "| elasticapm" in formatted_record + assert hasattr(record, "elasticapm_transaction_id") + record = logging.LogRecord(__name__, logging.DEBUG, __file__, 252, "dummy_msg", [], None) + formatted_time = formatter.formatTime(record) + assert formatted_time + assert hasattr(record, "elasticapm_transaction_id") From d21f88c97e954d716e7500d4b640d1b6180a8894 Mon Sep 17 00:00:00 2001 From: Colton Myers Date: Wed, 18 Sep 2019 15:01:34 -0600 Subject: [PATCH 2/5] Remove some unused imports --- tests/handlers/logging/logging_tests.py | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/tests/handlers/logging/logging_tests.py b/tests/handlers/logging/logging_tests.py index 3a477a32f..8155485f7 100644 --- a/tests/handlers/logging/logging_tests.py +++ b/tests/handlers/logging/logging_tests.py @@ -36,9 +36,9 @@ from elasticapm.conf import Config from elasticapm.conf.constants import ERROR -from elasticapm.handlers.logging import Formatter, LoggingFilter, LoggingHandler, log_record_factory +from elasticapm.handlers.logging import Formatter, LoggingFilter, LoggingHandler from elasticapm.handlers.structlog import structlog_processor -from elasticapm.traces import Tracer, capture_span, execution_context +from elasticapm.traces import Tracer, capture_span from elasticapm.utils import compat from elasticapm.utils.stacks import iter_stack_frames from tests.fixtures import TempStoreClient From 51e84e4d91e49a0203ad6445c6684f7b257a3402 Mon Sep 17 00:00:00 2001 From: Colton Myers Date: Wed, 18 Sep 2019 15:26:54 -0600 Subject: [PATCH 3/5] Add leading space for consistency with recommended grok pattern --- docs/logging.asciidoc | 2 +- elasticapm/handlers/logging.py | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/docs/logging.asciidoc b/docs/logging.asciidoc index 4df9a916a..54258360c 100644 --- a/docs/logging.asciidoc +++ b/docs/logging.asciidoc @@ -119,7 +119,7 @@ This will automatically append apm-specific fields to your format string: [source,python] ---- formatstring = "%(asctime)s - %(name)s - %(levelname)s - %(message)s" -formatstring = formatstring + "| elasticapm " \ +formatstring = formatstring + " | elasticapm " \ "transaction.id=%(elasticapm_transaction_id)s " \ "trace.id=%(elasticapm_trace_id)s " \ "span.id=%(elasticapm_span_id)s" diff --git a/elasticapm/handlers/logging.py b/elasticapm/handlers/logging.py index a2db177fc..36b173c93 100644 --- a/elasticapm/handlers/logging.py +++ b/elasticapm/handlers/logging.py @@ -233,7 +233,7 @@ class Formatter(logging.Formatter): LogRecordFactory): formatstring = "%(asctime)s - %(name)s - %(levelname)s - %(message)s" - formatstring = formatstring + "| elasticapm " \ + formatstring = formatstring + " | elasticapm " \ "transaction.id=%(elasticapm_transaction_id)s " \ "trace.id=%(elasticapm_trace_id)s " \ "span.id=%(elasticapm_span_id)s" @@ -243,7 +243,7 @@ def __init__(self, fmt=None, datefmt=None, style="%"): if fmt is None: fmt = "%(message)s" fmt = ( - fmt + "| elasticapm " + fmt + " | elasticapm " "transaction.id=%(elasticapm_transaction_id)s " "trace.id=%(elasticapm_trace_id)s " "span.id=%(elasticapm_span_id)s" From 97356916549a5af490bd9d75f73bbe0b1f532b6b Mon Sep 17 00:00:00 2001 From: Colton Myers Date: Wed, 18 Sep 2019 16:41:46 -0600 Subject: [PATCH 4/5] py2 compat --- elasticapm/handlers/logging.py | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/elasticapm/handlers/logging.py b/elasticapm/handlers/logging.py index 36b173c93..d5060513d 100644 --- a/elasticapm/handlers/logging.py +++ b/elasticapm/handlers/logging.py @@ -248,7 +248,10 @@ def __init__(self, fmt=None, datefmt=None, style="%"): "trace.id=%(elasticapm_trace_id)s " "span.id=%(elasticapm_span_id)s" ) - super(Formatter, self).__init__(fmt=fmt, datefmt=datefmt, style=style) + if compat.PY3: + super(Formatter, self).__init__(fmt=fmt, datefmt=datefmt, style=style) + else: + super(Formatter, self).__init__(fmt=fmt, datefmt=datefmt) def format(self, record): if not hasattr(record, "elasticapm_transaction_id"): From a99334a31829415737c0b6e26a9321e5ad2afc2d Mon Sep 17 00:00:00 2001 From: Colton Myers Date: Thu, 19 Sep 2019 09:26:16 -0600 Subject: [PATCH 5/5] Update bullets to match sidebar --- docs/advanced-topics.asciidoc | 2 ++ 1 file changed, 2 insertions(+) diff --git a/docs/advanced-topics.asciidoc b/docs/advanced-topics.asciidoc index 6ac1b46c6..39e67ff29 100644 --- a/docs/advanced-topics.asciidoc +++ b/docs/advanced-topics.asciidoc @@ -4,6 +4,8 @@ * <> * <> * <> +* <> +* <> include::./custom-instrumentation.asciidoc[Custom Instrumentation] include::./sanitizing-data.asciidoc[Sanitizing Data]