diff --git a/CHANGELOG.rst b/CHANGELOG.rst index af0d38d2..cd5cc357 100644 --- a/CHANGELOG.rst +++ b/CHANGELOG.rst @@ -4,6 +4,7 @@ CHANGELOG Unreleased ========== +* bugfix: [pymongo] Only record `ok`, `code`, `codeName`, `errorLabels` and `errtype` of failed commands unless `record_full_documents=True`. `errmsg` and other failure fields can contain document values and are no longer recorded by default. `https://github.com/aws/aws-xray-sdk-python/pull/495` 2.15.0 ========== diff --git a/aws_xray_sdk/ext/pymongo/patch.py b/aws_xray_sdk/ext/pymongo/patch.py index cd8df5d9..be520cbf 100644 --- a/aws_xray_sdk/ext/pymongo/patch.py +++ b/aws_xray_sdk/ext/pymongo/patch.py @@ -1,7 +1,12 @@ # Copyright © 2018 Clarity Movement Co. All rights reserved. +from collections.abc import Mapping + from pymongo import monitoring from aws_xray_sdk.core import xray_recorder +# failure fields that never contain document values +_SAFE_FAILURE_FIELDS = ('ok', 'code', 'codeName', 'errorLabels', 'errtype') + class XrayCommandListener(monitoring.CommandListener): """ @@ -10,7 +15,8 @@ class XrayCommandListener(monitoring.CommandListener): name: 'mydb@127.0.0.1:27017' records all available information provided by pymongo, - except for `command` and `reply`. They may contain business secrets. + except for `command`, `reply` and failure details. + They may contain business secrets. If you insist to record them, specify `record_full_documents=True`. """ @@ -43,7 +49,12 @@ def failed(self, event): subsegment = xray_recorder.current_subsegment() subsegment.add_fault_flag() subsegment.put_annotation('mongodb_duration_micros', event.duration_micros) - subsegment.put_metadata('failure', event.failure) + failure = event.failure + if not self.record_full_documents: + # pymongo may report None or a list as the failure + failure = {k: failure[k] for k in _SAFE_FAILURE_FIELDS + if isinstance(failure, Mapping) and k in failure} + subsegment.put_metadata('failure', failure) xray_recorder.end_subsegment() diff --git a/docs/thirdparty.rst b/docs/thirdparty.rst index c31e36a4..7bfe2acd 100644 --- a/docs/thirdparty.rst +++ b/docs/thirdparty.rst @@ -87,3 +87,17 @@ Patching httplib httplib is a low-level python module which is used by several third party modules, so by enabling patching to this module you can gain patching of many modules "for free." Some examples of modules that depend on httplib: requests and httplib2 + +Patching pymongo +---------------- + +By default the pymongo patch does not record command and reply documents, and only records +the ``ok``, ``code``, ``codeName``, ``errorLabels`` and ``errtype`` fields of failed commands, +because these documents may contain sensitive data. To record full documents, call the pymongo +patch directly before patching other modules:: + + from aws_xray_sdk.ext.pymongo import patch + + patch(record_full_documents=True) + +Note that this records every command, reply and failure document. diff --git a/tests/ext/pymongo/__init__.py b/tests/ext/pymongo/__init__.py new file mode 100644 index 00000000..e69de29b diff --git a/tests/ext/pymongo/test_pymongo.py b/tests/ext/pymongo/test_pymongo.py new file mode 100644 index 00000000..6abaf485 --- /dev/null +++ b/tests/ext/pymongo/test_pymongo.py @@ -0,0 +1,192 @@ +from types import SimpleNamespace + +import pytest +from bson import encode +from bson.raw_bson import RawBSONDocument +from pymongo import monitoring + +from aws_xray_sdk.core import xray_recorder +from aws_xray_sdk.core.context import Context +from aws_xray_sdk.ext.pymongo.patch import XrayCommandListener, patch + +SECRET = 'stored-secret-value' + +# $jsonSchema validation failure echoes the stored value in consideredValue +VALIDATION_FAILURE = { + 'ok': 0.0, + 'errmsg': 'Document failed validation', + 'code': 121, + 'codeName': 'DocumentValidationFailure', + 'errInfo': { + 'details': { + 'operatorName': '$jsonSchema', + 'schemaRulesNotSatisfied': [{ + 'operatorName': 'properties', + 'propertiesNotSatisfied': [{ + 'propertyName': 'api_token', + 'details': [{ + 'operatorName': 'pattern', + 'specifiedAs': {'pattern': '^vaulted:'}, + 'reason': 'regular expression did not match', + 'consideredValue': SECRET, + }], + }], + }], + }, + }, +} + +DUPLICATE_KEY_FAILURE = { + 'ok': 0.0, + 'errmsg': 'E11000 duplicate key error collection: db.users index: ' + 'token_1 dup key: { token: "%s" }' % SECRET, + 'code': 11000, + 'codeName': 'DuplicateKey', + 'keyPattern': {'token': 1}, + 'keyValue': {'token': SECRET}, +} + +TRANSACTION_FAILURE = { + 'ok': 0.0, + 'errmsg': 'Caused by :: Write conflict during plan execution', + 'code': 112, + 'codeName': 'WriteConflict', + 'errorLabels': ['TransientTransactionError'], +} + +# write concern errors have no `ok` field +WRITE_CONCERN_FAILURE = { + 'code': 64, + 'codeName': 'WriteConcernFailed', + 'errmsg': 'waiting for replication timed out', + 'errInfo': {'wtimeout': True}, + 'errorLabels': ['RetryableWriteError'], +} + +# failure document pymongo builds for client side errors +CLIENT_FAILURE = { + 'errmsg': 'localhost:27017: connection closed', + 'errtype': 'AutoReconnect', +} + + +@pytest.fixture(autouse=True) +def construct_ctx(): + """ + Clean up context storage on each test run and begin a segment + so that later subsegment can be attached. After each test run + it cleans up context storage again. + """ + xray_recorder.configure(service='test', sampling=False, context=Context()) + xray_recorder.clear_trace_entities() + xray_recorder.begin_segment('name') + yield + xray_recorder.clear_trace_entities() + + +def _started_event(): + return SimpleNamespace( + connection_id=('localhost', 27017), + database_name='db', + command_name='findAndModify', + operation_id=1, + request_id=2, + command={'findAndModify': 'users', 'update': {'$set': {'token': SECRET}}}, + ) + + +def _run_failed(listener, failure): + listener.started(_started_event()) + listener.failed(SimpleNamespace(duration_micros=10, failure=failure)) + return xray_recorder.current_segment().subsegments[0] + + +@pytest.mark.parametrize('failure', [VALIDATION_FAILURE, DUPLICATE_KEY_FAILURE]) +def test_failed_does_not_record_document_values(failure): + subsegment = _run_failed(XrayCommandListener(record_full_documents=False), failure) + + assert subsegment.fault + assert subsegment.metadata['default']['failure'] == { + 'ok': 0.0, + 'code': failure['code'], + 'codeName': failure['codeName'], + } + assert SECRET not in subsegment.serialize() + + +def test_failed_keeps_error_labels(): + subsegment = _run_failed(XrayCommandListener(record_full_documents=False), TRANSACTION_FAILURE) + + assert subsegment.metadata['default']['failure'] == { + 'ok': 0.0, + 'code': 112, + 'codeName': 'WriteConflict', + 'errorLabels': ['TransientTransactionError'], + } + + +def test_failed_write_concern_error(): + subsegment = _run_failed(XrayCommandListener(record_full_documents=False), WRITE_CONCERN_FAILURE) + + assert subsegment.metadata['default']['failure'] == { + 'code': 64, + 'codeName': 'WriteConcernFailed', + 'errorLabels': ['RetryableWriteError'], + } + + +def test_failed_raw_bson_document(): + failure = RawBSONDocument(encode(DUPLICATE_KEY_FAILURE)) + subsegment = _run_failed(XrayCommandListener(record_full_documents=False), failure) + + assert subsegment.metadata['default']['failure'] == { + 'ok': 0.0, + 'code': 11000, + 'codeName': 'DuplicateKey', + } + assert SECRET not in subsegment.serialize() + + +@pytest.mark.parametrize('failure', [None, ['code']]) +def test_failed_without_failure_document(failure): + subsegment = _run_failed(XrayCommandListener(record_full_documents=False), failure) + + assert subsegment.metadata['default']['failure'] == {} + assert not subsegment.in_progress + + +def test_failed_client_error_records_error_type(): + subsegment = _run_failed(XrayCommandListener(record_full_documents=False), CLIENT_FAILURE) + + assert subsegment.metadata['default']['failure'] == {'errtype': 'AutoReconnect'} + + +def test_failed_records_full_document_when_enabled(): + subsegment = _run_failed(XrayCommandListener(record_full_documents=True), VALIDATION_FAILURE) + + assert subsegment.metadata['default']['failure'] == VALIDATION_FAILURE + + +@pytest.mark.parametrize('record_full_documents', [False, True]) +def test_succeeded(record_full_documents): + listener = XrayCommandListener(record_full_documents=record_full_documents) + listener.started(_started_event()) + listener.succeeded(SimpleNamespace(duration_micros=10, reply={'ok': 1.0, 'value': {'token': SECRET}})) + subsegment = xray_recorder.current_segment().subsegments[0] + + assert subsegment.annotations['mongodb_command_name'] == 'findAndModify' + metadata = subsegment.metadata.get('default', {}) + assert ('mongodb_command' in metadata) is record_full_documents + assert ('mongodb_reply' in metadata) is record_full_documents + + +def test_patch_does_not_record_full_documents_by_default(monkeypatch): + registered = [] + monkeypatch.setattr(monitoring, 'register', registered.append) + monkeypatch.delattr(monitoring, '_xray_enabled', raising=False) + try: + patch() + finally: + vars(monitoring).pop('_xray_enabled', None) + + assert [listener.record_full_documents for listener in registered] == [False] diff --git a/tox.ini b/tox.ini index 7d9e50c4..5f2c3c40 100644 --- a/tox.ini +++ b/tox.ini @@ -32,6 +32,8 @@ envlist = py{37,38,39,310,311}-ext-psycopg + py{37,38,39,310,311,312}-ext-pymongo + py{37,38,39,310,311,312}-ext-pymysql py{37,38,39,310,311,312}-ext-pynamodb @@ -108,6 +110,8 @@ deps = ext-pg8000: pg8000 <= 1.20.0 ext-pg8000: testing.postgresql + ext-pymongo: pymongo + py{37,38,39,310,311,312}-ext-pymysql: pymysql >= 1.0.0 py{37,38,39,310,311,312}-ext-pymysql: cryptography @@ -145,6 +149,8 @@ commands = ext-psycopg: coverage run --append --source aws_xray_sdk -m pytest tests/ext/psycopg {posargs} + ext-pymongo: coverage run --append --source aws_xray_sdk -m pytest tests/ext/pymongo {posargs} + ext-pymysql: coverage run --append --source aws_xray_sdk -m pytest tests/ext/pymysql {posargs} ext-pynamodb: coverage run --append --source aws_xray_sdk -m pytest tests/ext/pynamodb {posargs}