From 6e8e566dadfd39c77737ac5243276256f87d492c Mon Sep 17 00:00:00 2001 From: Daniel Neilson <53624638+ddneilson@users.noreply.github.com> Date: Thu, 21 Mar 2024 15:11:53 -0500 Subject: [PATCH] feat: agent logs contain more verbose API request/response information (#215) Summary: Our current agent log is logging the API calls that it makes for auditing and debugging purposes. However, the API log didn't really contain sufficient information to understand what is happening; for example, we wouldn't know what sessionactions were assigned in an UpdateWorkerSchedule call, or whether the service told the agent to shutdown in a response to the same API. Further, our logs have a content filter that assumes that all request/responses are flat and that filtering decisions can be made only at the top-level. That is not the case for the AWS Deadline Cloud APIs that the agent calls; many of these have useful information throughout, but do contain some sensitive data deeply nested within structures that the agent should absolutely never log. This restricts the agent's ability to make fine grained filtering decisions, and forces it to generally choose to log very little from an API request/response. Solution: I reworked the API request/response filtering logic to allow for making filtering decisions deeply within nested structures, rather than just at the top level. I also created an ignore list where any API request that matches the ignore list will not appear in the log. API requests that are neither in the allow list nor ignore list are logged with heavy redaction. Then, I updated our filters to print much more useful information from the request/response of an API request. Furthermore, I added the request identifier to the API response log, and added UpdateWorkerSchedule to the filter so that customers can see that request as well. Signed-off-by: Daniel Neilson <53624638+ddneilson@users.noreply.github.com> --- src/deadline_worker_agent/session_events.py | 382 +++++++++++-- test/unit/test_session_events.py | 534 ++++++++++++++++-- .../posix_local_multiuser/Dockerfile | 3 + .../Dockerfile | 3 + 4 files changed, 834 insertions(+), 88 deletions(-) diff --git a/src/deadline_worker_agent/session_events.py b/src/deadline_worker_agent/session_events.py index dea88eb1..f9df6c51 100644 --- a/src/deadline_worker_agent/session_events.py +++ b/src/deadline_worker_agent/session_events.py @@ -1,10 +1,11 @@ # Copyright Amazon.com, Inc. or its affiliates. All Rights Reserved. import logging -from typing import Any, Dict, List, TypedDict, Union +from typing import Any, TypedDict, Union from typing_extensions import NotRequired import json -from typing import Any, Dict, List, TypedDict, Union +import datetime +import re log = logging.getLogger(__name__) @@ -19,10 +20,11 @@ class BotoLogStatement(TypedDict): operation: str # Only in requests request_url: NotRequired[str] - params: Union[List[Dict[str, Any]], Dict[str, Any]] + params: Union[dict[str, Any], str] # Only in responses error: NotRequired[str] status_code: NotRequired[str] + request_id: NotRequired[str] class Boto3ClientEvent: @@ -30,80 +32,364 @@ class Boto3ClientEvent: AFTER_CALL_PREFIX = "after-call" +# The actual type here is recursive: +# T = dict[str, T] | dict[str, bool] +# 1) If a key does not appear in this recursive dictionary, then it is +# never logged. +# 2) Only those keys that have a value that is True or a dictionary are logged. +AllowableBodyKeysT = dict[str, Any] + + class LoggingAllowList(TypedDict, total=False): # RESTful services have IDs in the url # set this to true to include the request URL in the logs log_request_url: bool - # keys to log for this operation from the request's body - req_body_keys: List[str] - # keys to log for this operation from the response's body - res_body_keys: List[str] + # Parts of the request to log. + req_log_body: AllowableBodyKeysT + # Parts of the response to log. + res_log_body: AllowableBodyKeysT -LOGGING_ALLOW_LIST: Dict[str, LoggingAllowList] = { - "deadline.CreateWorker": {"log_request_url": True, "res_body_keys": ["workerId"]}, - "deadline.AssumeFleetRoleForWorker": {"log_request_url": True}, - "deadline.AssumeQueueRoleForWorker": {"log_request_url": True}, +# The AWS API calls that we log, and the specific request/response properties that we log. +# Note: The log must NEVER contain customer personal information, or information that a customer +# might consider secret/sensitive. +LOGGING_ALLOW_LIST: dict[str, LoggingAllowList] = { + "deadline.CreateWorker": { + "log_request_url": True, + "req_log_body": {"hostProperties": True}, + "res_log_body": {"workerId": True}, + }, + "deadline.AssumeFleetRoleForWorker": { + "log_request_url": True, + # req_log_body -- no body to log + "res_log_body": { + "credentials": { + "accessKeyId": True, # Not a secret + "expiration": True + # exclude: secretAccessKey & sessionToken + } + }, + }, + "deadline.AssumeQueueRoleForWorker": { + "log_request_url": True, + # req_log_body -- no body to log + "res_log_body": { + "credentials": { + "accessKeyId": True, # Not a secret + "expiration": True + # exclude: secretAccessKey & sessionToken + } + }, + }, "deadline.UpdateWorker": { "log_request_url": True, - "req_body_keys": ["status"], - "res_body_keys": ["log"], + "req_log_body": { + "status": True, + # capabilities are not sensitive. They're treated like AWS Tags for privacy. + "capabilities": True, + "hostProperties": True, + }, + "res_log_body": {"log": True}, + }, + "deadline.UpdateWorkerSchedule": { + "log_request_url": True, + "req_log_body": { + "updatedSessionActions": { + # Key is a Session Action Id + "*": { + "completedStatus": True, + "processExitCode": True, + "startedAt": True, + "endedAt": True, + "updatedAt": True, + "progressPercent": True, + # progressMessage excluded + }, + } + }, + "res_log_body": { + # assignedSessions only contains non-sensitive data by design. + "assignedSessions": { + "*": { + "queueId": True, + "jobId": True, + "sessionActions": { # is an array of objects + "sessionActionId": True, + "definition": { + "envEnter": {"environmentId": True}, + "envExit": {"environmentId": True}, + "taskRun": { + "taskId": True, + "stepId": True, + # parameters excluded. It's sensitive for the Agent log since the parameter + # names may have meaning to the customer. It should only appear in the session log. + }, + "syncInputJobAttachments": {"stepId": True}, + }, + }, + "logConfiguration": True, # log the entire dictionary + }, + }, + "cancelSessionActions": True, # array of IDs. Log the whole thing + "desiredWorkerStatus": True, + "updateIntervalSeconds": True, + }, + }, + "deadline.BatchGetJobEntity": { + "log_request_url": True, + "req_log_body": { + "identifiers": True, # only contains identifiers + }, + "res_log_body": { + "entities": { + "jobDetails": { + "jobId": True, + "jobAttachmentSettings": {"s3BucketName": True, "rootPrefix": True}, + "jobRunAsUser": True, + "logGroupName": True, + "queueRoleArn": True, + # parameters excluded. It's sensitive for the Agent log since the parameter + # names may have meaning to the customer. It should only appear in the session log. + "schemaVersion": True, + "pathMappingRules": False, # will contain filesystem paths; err on the side of caution + }, + "jobAttachmentDetails": { + "jobId": True, + "attachments": { + "manifests": { # array of objects + "fileSystemLocationName": True, + "rootPath": False, # will contain filesystem paths; err on the side of caution + "rootPathFormat": True, + "outputRelativeDirectories": False, # will contain filesystem paths; err on the side of caution + "inputManifestPath": True, + "inputManifestHash": True, + }, + "fileSystem": True, + }, + }, + "environmentDetails": { + "jobId": True, + "environmentId": True, + "schemaVersion": True, + # template excluded. It's sensitive; it contains the commands to run + }, + "stepDetails": { + "jobId": True, + "stepId": True, + "schemaVersion": True, + "dependencies": True, # list of step IDs + # template excluded. It's sensitive; it contains the commands to run + }, + }, + "errors": True, # log all errors + }, + }, + "deadline.DeleteWorker": { + "log_request_url": True, + # request is empty + # response is empty + }, + # ========================= + # Non-Deadline Services + "secretsmanager.GetSecretValue": { + "log_request_url": True, + "req_log_body": {"SecretId": True, "VersionId": True, "VersionStage": True}, + "res_log_body": { + "ARN": True, + "CreatedDate": True, + "Name": True, + "VersionId": True + # excluding: SecretString/SecretBinary, for obvious reasons + # excluding VersionStages; seems unnecessary + }, }, - "deadline.BatchGetJobEntity": {"log_request_url": True}, - "deadline.DeleteWorker": {"log_request_url": True}, } +# Not logging: +# cloudwatch.PutLogEvents -- logging that you're logging just clutters the log +# s3.* -- For now. Very verbose to be logging these dataplane APIs; maybe when we have a verbose log mode. +_IGNORE_LIST = ["cloudwatch-logs\..*", "s3\..*"] +LOGGING_IGNORE_MATCHER = re.compile("^(" + "|".join(_IGNORE_LIST) + ")$") + + +def _get_loggable_parameters( + body: dict[str, Any], allowable_keys: AllowableBodyKeysT +) -> dict[str, Any]: + to_be_logged = dict[str, Any]() + if body is None: # Handle the None case + return to_be_logged + for k, v in body.items(): + if k not in allowable_keys: + if "*" not in allowable_keys: + to_be_logged[k] = "*REDACTED*" + continue + allow_key = "*" + else: + allow_key = k + allowable = allowable_keys[allow_key] + if isinstance(v, datetime.datetime): + v = str(v) + if isinstance(allowable, bool): + if allowable: + to_be_logged[k] = v + else: + to_be_logged[k] = "*REDACTED*" + elif isinstance(v, dict): + to_be_logged[k] = _get_loggable_parameters(v, allowable) + elif isinstance(v, list): + to_be_logged[k] = [_get_loggable_parameters(vv, allowable) for vv in v] + return to_be_logged + def log_before_call(event_name, params, **kwargs) -> None: # event name is of the form `before_call.{operation}` + # params looks like: + # { + # "url_path": "/...", + # "query_string": {}, + # "method": "POST", + # "headers": { + # "X-Amz-Client-Token": "f3a3e84d-f024-4caa-87a7-4a83e1361fef", + # "Content-Type": "application/json", + # "User-Agent": + # }, + # "body": b"...", + # "url": "https://....amazonaws.com/...", + # "context": { + # "client_region": "us-west-2", + # "client_config": , + # "has_streaming_input": False, + # "auth_type": None + # } + # } try: operation_name = event_name.split(".", 1)[1] + if LOGGING_IGNORE_MATCHER.match(operation_name): + return + body = params["body"] + if isinstance(body, bytes): + if body == b"": + body = None + # Body can be string or bytes + else: + body = body.decode() + if isinstance(body, str): + body = json.loads(body) + loggable_params: Union[dict[str, Any], str] = {} if operation_name in LOGGING_ALLOW_LIST: allow_list = LOGGING_ALLOW_LIST[operation_name] - body = params["body"] - if isinstance(body, bytes): - if body == b"": - body = None - # Body can be string or bytes - else: - body = body.decode() - if isinstance(body, str): - body = json.loads(body) if allow_list.get("log_request_url", True): url = params.get("url") - loggable_params = {key: body.get(key) for key in allow_list.get("req_body_keys", [])} - log_statement: BotoLogStatement = { - "log_type": "boto_request", - "operation": operation_name, - "params": loggable_params, - } # noqa - if url is not None: - log_statement["request_url"] = url - log.info(log_statement) + allowable_response_fields = allow_list.get("req_log_body", dict()) + loggable_params = _get_loggable_parameters(body, allowable_response_fields) + else: + loggable_params = "*REDACTED*" + url = "*REDACTED*" + log_statement: BotoLogStatement = { + "log_type": "boto_request", + "operation": operation_name, + "params": loggable_params, + } # noqa + if url is not None: + log_statement["request_url"] = url + log.info(json.dumps(log_statement)) except Exception: log.exception(f"Error Logging Boto Request with name {event_name}!") def log_after_call(event_name, parsed, **kwargs) -> None: # event name is of the form `after_call.{operation}` + # parsed looks like: + # { + # "ResponseMetadata": { + # "RequestId": "9885082b-3d0a-40f3-854a-223aa86f549b", + # "HTTPStatusCode": 200, + # "HTTPHeaders": { + # "date": "Sun,17 Mar 2024 19: 08: 19 GMT", + # "content-type": "application/json", + # "content-length": "81", + # "connection": "keep-alive", + # "x-amzn-requestid": "9885082b-3d0a-40f3-854a-223aa86f549b", + # "access-control-allow-origin": "*", + # "access-control-expose-headers-age": "86400", + # "x-amz-apigw-id": , + # "cache-control": "no-cache; no-store, must-revalidate, private", + # "expires": "0", + # "access-control-allow-methods": "GET,PATCH,POST,PUT,DELETE", + # "access-control-expose-headers": "x-amzn-ErrorType,x-amzn-requestid,x-amzn-trace-id,x-amz-apigw-id", + # "x-amzn-trace-id": "Root=1-65f73fa2-3b164cfd5721593c539e68b4", + # "pragma": "no-cache", + # "access-control-max-age": "86400" + # }, + # "RetryAttempts": 0 + # }, + # ... fields of the response. + # } + # + # OR + # + # { + # "ResponseMetadata": { + # "RequestId": "9885082b-3d0a-40f3-854a-223aa86f549b", + # "HTTPStatusCode": 200, + # "HTTPHeaders": { + # "date": "Sun,17 Mar 2024 19: 08: 19 GMT", + # "content-type": "application/json", + # "content-length": "81", + # "connection": "keep-alive", + # "x-amzn-requestid": "9885082b-3d0a-40f3-854a-223aa86f549b", + # "access-control-allow-origin": "*", + # "access-control-expose-headers-age": "86400", + # "x-amz-apigw-id": , + # "cache-control": "no-cache; no-store, must-revalidate, private", + # "expires": "0", + # "access-control-allow-methods": "GET,PATCH,POST,PUT,DELETE", + # "access-control-expose-headers": "x-amzn-ErrorType,x-amzn-requestid,x-amzn-trace-id,x-amz-apigw-id", + # "x-amzn-trace-id": "Root=1-65f73fa2-3b164cfd5721593c539e68b4", + # "pragma": "no-cache", + # "access-control-max-age": "86400" + # }, + # "Error": { + # "Message": "", + # "Code": "ConflictException" + # }, + # # The following are properties of the exception raised by the service + # # They don't need to be redacted in logs + # "message": " None: caplog.set_level(0) log_before_call(event_name, params) assert caplog.messages == [expected_result] +@pytest.mark.parametrize( + argnames=("api_name", "params"), + argvalues=( + pytest.param( + "cloudwatch-logs.PutLogEvent", + { + "url_path": "/", + "body": '{"requestParam": "requestValue"}', + "url": "https://cloudwatch-logs.us-west-2.amazonaws.com/", + }, + id="IgnoreCloudWatchBeforeCall", + ), + pytest.param( + "s3.GetObject", + { + "url_path": "/", + "body": '{"requestParam": "requestValue"}', + "url": "https://s3.us-west-2.amazonaws.com/", + }, + id="IgnoreS3BeforeCall", + ), + ), +) +def test_log_before_ignore_list( + api_name: str, params: Dict[str, Any], caplog: pytest.LogCaptureFixture +) -> None: + caplog.set_level(0) + log_before_call("before-call." + api_name, params) + assert all(api_name not in msg for msg in caplog.messages) + + @pytest.mark.parametrize( argnames=("event_name", "params", "expected_result"), argvalues=( @@ -140,7 +370,7 @@ def test_log_before_call( }, "workerId": "worker-38aab2f87d2b45298b39875639580970", }, - "{'log_type': 'boto_response', 'operation': 'deadline.CreateWorker', 'status_code': 200, 'params': {'workerId': 'worker-38aab2f87d2b45298b39875639580970'}}", + '{"log_type": "boto_response", "operation": "deadline.CreateWorker", "status_code": 200, "params": {"workerId": "worker-38aab2f87d2b45298b39875639580970"}, "request_id": "abc878ee-32b5-44d4-885f-29071648328c"}', id="CreateWorkerAfterCallTest", ), pytest.param( @@ -149,10 +379,16 @@ def test_log_before_call( "ResponseMetadata": { "RequestId": "abc878ee-32b5-44d4-885f-29071648328c", "HTTPStatusCode": 200, - } + }, + "credentials": { + "accessKeyId": "accesskey", + "secretAccessKey": "secretkey", + "sessionToken": "token", + "expiration": "some date", + }, }, - "{'log_type': 'boto_response', 'operation': 'deadline.AssumeFleetRoleForWorker', 'status_code': 200, 'params': {}}", - id="AssumeFleetRoleAfterCallTest", + '{"log_type": "boto_response", "operation": "deadline.AssumeFleetRoleForWorker", "status_code": 200, "params": {"credentials": {"accessKeyId": "accesskey", "secretAccessKey": "*REDACTED*", "sessionToken": "*REDACTED*", "expiration": "some date"}}, "request_id": "abc878ee-32b5-44d4-885f-29071648328c"}', + id="AssumeFleetRoleForWorkerAfterCallTest", ), pytest.param( "after-call.deadline.AssumeQueueRoleForWorker", @@ -160,9 +396,15 @@ def test_log_before_call( "ResponseMetadata": { "RequestId": "abc878ee-32b5-44d4-885f-29071648328c", "HTTPStatusCode": 200, - } + }, + "credentials": { + "accessKeyId": "accesskey", + "secretAccessKey": "secretkey", + "sessionToken": "token", + "expiration": "some date", + }, }, - "{'log_type': 'boto_response', 'operation': 'deadline.AssumeQueueRoleForWorker', 'status_code': 200, 'params': {}}", + '{"log_type": "boto_response", "operation": "deadline.AssumeQueueRoleForWorker", "status_code": 200, "params": {"credentials": {"accessKeyId": "accesskey", "secretAccessKey": "*REDACTED*", "sessionToken": "*REDACTED*", "expiration": "some date"}}, "request_id": "abc878ee-32b5-44d4-885f-29071648328c"}', id="AssumeQueueRoleForWorkerAfterCallTest", ), pytest.param( @@ -172,20 +414,146 @@ def test_log_before_call( "RequestId": "abc878ee-32b5-44d4-885f-29071648328c", "HTTPStatusCode": 200, }, - "status": "STOPPED", + "log": { + "logDriver": "AWS", + "options": {"option1": "foo"}, + "parameters": {"param1": "bar"}, + "error": "AccessDeniedException", + }, }, - "{'log_type': 'boto_response', 'operation': 'deadline.UpdateWorker', 'status_code': 200, 'params': {'log': None}}", + '{"log_type": "boto_response", "operation": "deadline.UpdateWorker", "status_code": 200, "params": {"log": {"logDriver": "AWS", "options": {"option1": "foo"}, "parameters": {"param1": "bar"}, "error": "AccessDeniedException"}}, "request_id": "abc878ee-32b5-44d4-885f-29071648328c"}', id="UpdateWorkerAfterCallTest", ), + pytest.param( + "after-call.deadline.UpdateWorkerSchedule", + { + "ResponseMetadata": { + "RequestId": "abc878ee-32b5-44d4-885f-29071648328c", + "HTTPStatusCode": 200, + }, + "assignedSessions": { + "session-e4ffe548f48d456ca11b5337bdc7a175": { + "queueId": "queue-f9848b67822d49299296e3e47d8cc523", + "jobId": "job-ac95524e7128498b9082375f8e3d7665", + "sessionActions": [ + { + "sessionActionId": "sessionaction-e4ffe548f48d456ca11b5337bdc7a175-0", + "definition": { + "envEnter": { + "environmentId": "JOB:job-ac95524e7128498b9082375f8e3d7665:TestEnvironment" + } + }, + }, + { + "sessionActionId": "sessionaction-e4ffe548f48d456ca11b5337bdc7a175-1", + "definition": { + "envEnter": { + "environmentId": "STEP:step-ff15e0f18561495399cb07b64342b538:myenv" + } + }, + }, + { + "sessionActionId": "sessionaction-e4ffe548f48d456ca11b5337bdc7a175-2", + "definition": { + "taskRun": { + "taskId": "task-ff15e0f18561495399cb07b64342b538-0", + "stepId": "step-ff15e0f18561495399cb07b64342b538", + "parameters": {"Foo": "FooValue"}, + } + }, + }, + { + "sessionActionId": "sessionaction-e4ffe548f48d456ca11b5337bdc7a175-3", + "definition": { + "syncInputJobAttachments": { + "stepId": "step-ff15e0f18561495399cb07b64342b500", + } + }, + }, + ], + "logConfiguration": { + "logDriver": "AWS", + "options": {"option1": "foo"}, + "parameters": {"param1": "bar"}, + "error": "AccessDeniedException", + }, + }, + }, + }, + '{"log_type": "boto_response", "operation": "deadline.UpdateWorkerSchedule", "status_code": 200, "params": {"assignedSessions": {"session-e4ffe548f48d456ca11b5337bdc7a175": {"queueId": "queue-f9848b67822d49299296e3e47d8cc523", "jobId": "job-ac95524e7128498b9082375f8e3d7665", "sessionActions": [{"sessionActionId": "sessionaction-e4ffe548f48d456ca11b5337bdc7a175-0", "definition": {"envEnter": {"environmentId": "JOB:job-ac95524e7128498b9082375f8e3d7665:TestEnvironment"}}}, {"sessionActionId": "sessionaction-e4ffe548f48d456ca11b5337bdc7a175-1", "definition": {"envEnter": {"environmentId": "STEP:step-ff15e0f18561495399cb07b64342b538:myenv"}}}, {"sessionActionId": "sessionaction-e4ffe548f48d456ca11b5337bdc7a175-2", "definition": {"taskRun": {"taskId": "task-ff15e0f18561495399cb07b64342b538-0", "stepId": "step-ff15e0f18561495399cb07b64342b538", "parameters": "*REDACTED*"}}}, {"sessionActionId": "sessionaction-e4ffe548f48d456ca11b5337bdc7a175-3", "definition": {"syncInputJobAttachments": {"stepId": "step-ff15e0f18561495399cb07b64342b500"}}}], "logConfiguration": {"logDriver": "AWS", "options": {"option1": "foo"}, "parameters": {"param1": "bar"}, "error": "AccessDeniedException"}}}}, "request_id": "abc878ee-32b5-44d4-885f-29071648328c"}', + id="UpdateWorkerScheduleAfterCallTest", + ), pytest.param( "after-call.deadline.BatchGetJobEntity", { "ResponseMetadata": { "RequestId": "abc878ee-32b5-44d4-885f-29071648328c", "HTTPStatusCode": 200, - } + }, + "entities": [ + { + "jobDetails": { + "jobId": "job-ac95524e7128498b9082375f8e3d7665", + "jobAttachmentSettings": { + "s3BucketName": "bucketname", + "rootPrefix": "assets/", + }, + "jobRunAsUser": { + "posix": {"user": "jobuser", "group": "jobuser"}, + "windows": { + "user": "jobuser", + "passwordArn": "arn:aws:secretsmanager:us-west-2:000000000000:secret:PasswordSecret-qsrF9d", + }, + "runAs": "QUEUE_CONFIGURED_USER", + }, + "logGroupName": "/aws/deadline/farm-1b84ca8d938d47d99a00675ff4eedd41/queue-f9848b67822d49299296e3e47d8cc523", + "queueRoleArn": "arn:aws:iam::000000000000:role/QueueRole", + "parameters": {"Foo": "FooValue"}, + "schemaVersion": "jobtemplate-2023-09", + }, + "stepDetails": { + "jobId": "job-ac95524e7128498b9082375f8e3d7665", + "stepId": "step-ff15e0f18561495399cb07b64342b538", + "schemaVersion": "jobtemplate-2023-09", + "template": { + "name": "StepName", + "script": { + "actions": {"onRun": {"command": "echo", "args": ["Hi"]}} + }, + }, + "dependencies": ["step-ff15e0f18561495399cb07b64342b500"], + }, + "environmentDetails": { + "jobId": "job-ac95524e7128498b9082375f8e3d7665", + "environmentId": "JOB:job-ac95524e7128498b9082375f8e3d7665:TestEnvironment", + "schemaVersion": "jobtemplate-2023-09", + "template": { + "name": "TestEnvironment", + "script": { + "actions": {"onEnter": {"command": "echo", "args": ["hi"]}} + }, + }, + }, + "jobAttachmentDetails": { + "jobId": "job-ac95524e7128498b9082375f8e3d7665", + "attachments": { + "manifests": [ + { + "fileSystemLocationName": "Filesystem", + "rootPath": "/mnt/shared", + "rootPathFormat": "posix", + "outputRelativeDirectories": ["../output"], + "inputManifestPath": "manifest_file", + "inputManifestHash": "1234", + } + ], + "fileSystem": "COPIED", + }, + }, + } + ], }, - "{'log_type': 'boto_response', 'operation': 'deadline.BatchGetJobEntity', 'status_code': 200, 'params': {}}", + '{"log_type": "boto_response", "operation": "deadline.BatchGetJobEntity", "status_code": 200, "params": {"entities": [{"jobDetails": {"jobId": "job-ac95524e7128498b9082375f8e3d7665", "jobAttachmentSettings": {"s3BucketName": "bucketname", "rootPrefix": "assets/"}, "jobRunAsUser": {"posix": {"user": "jobuser", "group": "jobuser"}, "windows": {"user": "jobuser", "passwordArn": "arn:aws:secretsmanager:us-west-2:000000000000:secret:PasswordSecret-qsrF9d"}, "runAs": "QUEUE_CONFIGURED_USER"}, "logGroupName": "/aws/deadline/farm-1b84ca8d938d47d99a00675ff4eedd41/queue-f9848b67822d49299296e3e47d8cc523", "queueRoleArn": "arn:aws:iam::000000000000:role/QueueRole", "parameters": "*REDACTED*", "schemaVersion": "jobtemplate-2023-09"}, "stepDetails": {"jobId": "job-ac95524e7128498b9082375f8e3d7665", "stepId": "step-ff15e0f18561495399cb07b64342b538", "schemaVersion": "jobtemplate-2023-09", "template": "*REDACTED*", "dependencies": ["step-ff15e0f18561495399cb07b64342b500"]}, "environmentDetails": {"jobId": "job-ac95524e7128498b9082375f8e3d7665", "environmentId": "JOB:job-ac95524e7128498b9082375f8e3d7665:TestEnvironment", "schemaVersion": "jobtemplate-2023-09", "template": "*REDACTED*"}, "jobAttachmentDetails": {"jobId": "job-ac95524e7128498b9082375f8e3d7665", "attachments": {"manifests": [{"fileSystemLocationName": "Filesystem", "rootPath": "*REDACTED*", "rootPathFormat": "posix", "outputRelativeDirectories": "*REDACTED*", "inputManifestPath": "manifest_file", "inputManifestHash": "1234"}], "fileSystem": "COPIED"}}}]}, "request_id": "abc878ee-32b5-44d4-885f-29071648328c"}', id="BatchGetJobEntityAfterCallTest", ), pytest.param( @@ -194,11 +562,61 @@ def test_log_before_call( "ResponseMetadata": { "RequestId": "abc878ee-32b5-44d4-885f-29071648328c", "HTTPStatusCode": 200, - } + }, }, - "{'log_type': 'boto_response', 'operation': 'deadline.DeleteWorker', 'status_code': 200, 'params': {}}", + '{"log_type": "boto_response", "operation": "deadline.DeleteWorker", "status_code": 200, "params": {}, "request_id": "abc878ee-32b5-44d4-885f-29071648328c"}', id="DeleteWorkerAfterCallTest", ), + # ==================== + # Unknown API tests -- make sure that we redact the params, but still report the API + pytest.param( + "before-call.deadline.NotAnAPI", + { + "ResponseMetadata": { + "RequestId": "abc878ee-32b5-44d4-885f-29071648328c", + "HTTPStatusCode": 200, + }, + "ResponseParam": "ResponseValue", + }, + '{"log_type": "boto_response", "operation": "deadline.NotAnAPI", "status_code": 200, "params": "*REDACTED*", "request_id": "abc878ee-32b5-44d4-885f-29071648328c"}', + id="NotAnAPIBeforeCallTest", + ), + # ==================== + pytest.param( + "after-call.secretsmanager.GetSecretValue", + { + "ResponseMetadata": { + "RequestId": "abc878ee-32b5-44d4-885f-29071648328c", + "HTTPStatusCode": 200, + }, + "ARN": "arn:aws:secretsmanager:us-west-2:000000000000:secret:Secret-qsrF9d", + "Name": "Secret", + "VersionId": "6fb9f17a-f9a9-4729-af0f-df67e976484c", + "SecretString": '{"username": "fakeuser", "password": "fakepassword"}', + "SecretBinary": b"abdc", + "VersionStages": ["AWSCURRENT"], + "CreatedDate": datetime.datetime( + 2021, 4, 27, 14, 8, 44, 337000, tzinfo=datetime.timezone.utc + ), + }, + '{"log_type": "boto_response", "operation": "secretsmanager.GetSecretValue", "status_code": 200, "params": {"ARN": "arn:aws:secretsmanager:us-west-2:000000000000:secret:Secret-qsrF9d", "Name": "Secret", "VersionId": "6fb9f17a-f9a9-4729-af0f-df67e976484c", "SecretString": "*REDACTED*", "SecretBinary": "*REDACTED*", "VersionStages": "*REDACTED*", "CreatedDate": "2021-04-27 14:08:44.337000+00:00"}, "request_id": "abc878ee-32b5-44d4-885f-29071648328c"}', + id="GetSecretValueAfterCallTest", + ), + # ==================== + # Test that the error is logged + pytest.param( + "after-call.deadline.CreateWorker", + { + "ResponseMetadata": { + "RequestId": "abc878ee-32b5-44d4-885f-29071648328c", + "HTTPStatusCode": 500, + }, + "Error": {"Message": "This is a test", "Code": "InternalServerException"}, + "reason": "CONFLICT_EXCEPTION", + }, + '{"log_type": "boto_response", "operation": "deadline.CreateWorker", "status_code": 500, "params": {"reason": "CONFLICT_EXCEPTION"}, "error": {"Message": "This is a test", "Code": "InternalServerException"}, "request_id": "abc878ee-32b5-44d4-885f-29071648328c"}', + id="ErrorCase", + ), ), ) def test_log_after_call( @@ -207,3 +625,39 @@ def test_log_after_call( caplog.set_level(0) log_after_call(event_name, params) assert caplog.messages == [expected_result] + + +@pytest.mark.parametrize( + argnames=("api_name", "params"), + argvalues=( + pytest.param( + "cloudwatch-logs.PutLogEvent", + { + "ResponseMetadata": { + "RequestId": "abc878ee-32b5-44d4-885f-29071648328c", + "HTTPStatusCode": 200, + }, + "SomeResponseParam": "ResponseValue", + }, + id="IgnoreCloudWatchAfterCall", + ), + pytest.param( + "s3.GetObject", + { + "ResponseMetadata": { + "RequestId": "abc878ee-32b5-44d4-885f-29071648328c", + "HTTPStatusCode": 200, + }, + "SomeResponseParam": "ResponseValue", + }, + id="IgnoreS3AfterCall", + ), + ), +) +def test_log_after_ignore_list( + api_name: str, params: Dict[str, Any], caplog: pytest.LogCaptureFixture +) -> None: + caplog.set_level(0) + log_before_call("after-call." + api_name, params) + + assert all(api_name not in msg for msg in caplog.messages) diff --git a/testing_containers/posix_local_multiuser/Dockerfile b/testing_containers/posix_local_multiuser/Dockerfile index 8c4c6870..fc37e7f7 100644 --- a/testing_containers/posix_local_multiuser/Dockerfile +++ b/testing_containers/posix_local_multiuser/Dockerfile @@ -29,6 +29,9 @@ RUN chmod 777 /code /aws && \ chown ${AGENT_USER}:${AGENT_USER} /var/log/amazon/deadline && \ chmod 700 /var/log/amazon/deadline && \ mkdir -p /var/lib/deadline && \ + mkdir -p /var/tmp/openjd && \ + chown ${AGENT_USER}:${SHARED_GROUP} /var/tmp/openjd && \ + chmod 755 /var/tmp/openjd && \ # Shared directory for sharing credentials process with the job user. mkdir -p /var/lib/deadline/queues && \ chown ${AGENT_USER}:${SHARED_GROUP} /var/lib/deadline /var/lib/deadline/queues && \ diff --git a/testing_containers/posix_local_multiuser_jobRunAsUser/Dockerfile b/testing_containers/posix_local_multiuser_jobRunAsUser/Dockerfile index 8c4c6870..fc37e7f7 100644 --- a/testing_containers/posix_local_multiuser_jobRunAsUser/Dockerfile +++ b/testing_containers/posix_local_multiuser_jobRunAsUser/Dockerfile @@ -29,6 +29,9 @@ RUN chmod 777 /code /aws && \ chown ${AGENT_USER}:${AGENT_USER} /var/log/amazon/deadline && \ chmod 700 /var/log/amazon/deadline && \ mkdir -p /var/lib/deadline && \ + mkdir -p /var/tmp/openjd && \ + chown ${AGENT_USER}:${SHARED_GROUP} /var/tmp/openjd && \ + chmod 755 /var/tmp/openjd && \ # Shared directory for sharing credentials process with the job user. mkdir -p /var/lib/deadline/queues && \ chown ${AGENT_USER}:${SHARED_GROUP} /var/lib/deadline /var/lib/deadline/queues && \