Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

fix: move logging of input/output and req/res to serde #1526

Merged
merged 6 commits into from
Sep 15, 2020
Merged

fix: move logging of input/output and req/res to serde #1526

merged 6 commits into from
Sep 15, 2020

Conversation

trivikr
Copy link
Member

@trivikr trivikr commented Sep 14, 2020 •
edited
Loading

Issue #, if available:
Follow up to #1478

Description of changes:
move logging of input/output and req/res to serde

What does it do?
It moves logging of input before just before serializing and request just after serializing. It also moves logging of response just before deserializing, and output just after deserializing. It also converts deser to arrow functions and adds unit tests for them.

Why is it helpful?
The current logger middleware logs input/output/request/response in build step, and they may be edited by other middleware (like several s3 customization middleware now, or DynamoDB Document Client in future). This PR ensures that the actually sent/received values are logged.

Test code 
const { DynamoDB } = require("@aws-sdk/client-dynamodb");

// We're using Pino, customer can pass any logger
const logger = require("pino")({
  level: process.env.LOG_LEVEL || "info",
  prettyPrint: true,
});

(async () => {
  const client = new DynamoDB({ logger });
  await client.listTables({ Limit: 1 });
})();
Output with default LOG_LEVEL=info 
[1600118095663] INFO  (70609 on 186590ce2139):
    input: {
      "Limit": 1
    }
[1600118096387] INFO  (70609 on 186590ce2139):
    output: {
      "__type": "ListTablesOutput",
      "LastEvaluatedTableName": "CUSTOMER_LIST",
      "TableNames": [
        "CUSTOMER_LIST"
      ]
    }
[1600118096387] INFO  (70609 on 186590ce2139):
    $metadata: {
      "httpStatusCode": 200,
      "httpHeaders": {
        "server": "Server",
        "date": "Mon, 14 Sep 2020 21:14:41 GMT",
        "content-type": "application/x-amz-json-1.0",
        "content-length": "73",
        "connection": "keep-alive",
        "x-amzn-requestid": "0IG5NTHKJS423VET0CJVG8LF1NVV4KQNSO5AEMVJF66Q9ASUAAJG",
        "x-amz-crc32": "773170490"
      },
      "requestId": "0IG5NTHKJS423VET0CJVG8LF1NVV4KQNSO5AEMVJF66Q9ASUAAJG",
      "attempts": 1,
      "totalRetryDelay": 0
    }
Output with LOG_LEVEL=debug 
[1600118145240] INFO  (71284 on 186590ce2139):
    input: {
      "Limit": 1
    }
[1600118145247] DEBUG (71284 on 186590ce2139):
    httpRequest: {
      "method": "POST",
      "hostname": "dynamodb.us-west-2.amazonaws.com",
      "query": {},
      "headers": {
        "Content-Type": "application/x-amz-json-1.0",
        "X-Amz-Target": "DynamoDB_20120810.ListTables"
      },
      "body": "{\"Limit\":1}",
      "protocol": "https:",
      "path": "/"
    }
[1600118146024] DEBUG (71284 on 186590ce2139):
    httpResponse: {
      "statusCode": 200,
      "headers": {
        "server": "Server",
        "date": "Mon, 14 Sep 2020 21:15:31 GMT",
        "content-type": "application/x-amz-json-1.0",
        "content-length": "73",
        "connection": "keep-alive",
        "x-amzn-requestid": "EE8GSKGB44RASB525APL32B6TVVV4KQNSO5AEMVJF66Q9ASUAAJG",
        "x-amz-crc32": "773170490"
      },
      "body": { ...<BODY>... }
    }
[1600118146056] INFO  (71284 on 186590ce2139):
    output: {
      "__type": "ListTablesOutput",
      "LastEvaluatedTableName": "CUSTOMER_LIST",
      "TableNames": [
        "CUSTOMER_LIST"
      ]
    }
[1600118146058] INFO  (71284 on 186590ce2139):
    $metadata: {
      "httpStatusCode": 200,
      "httpHeaders": {
        "server": "Server",
        "date": "Mon, 14 Sep 2020 21:15:31 GMT",
        "content-type": "application/x-amz-json-1.0",
        "content-length": "73",
        "connection": "keep-alive",
        "x-amzn-requestid": "EE8GSKGB44RASB525APL32B6TVVV4KQNSO5AEMVJF66Q9ASUAAJG",
        "x-amz-crc32": "773170490"
      },
      "requestId": "EE8GSKGB44RASB525APL32B6TVVV4KQNSO5AEMVJF66Q9ASUAAJG",
      "attempts": 1,
      "totalRetryDelay": 0
    }

By submitting this pull request, I confirm that you can use, modify, copy, and redistribute this contribution, under the terms of your choice.

@codecov-commenter
Copy link

codecov-commenter commented Sep 14, 2020 •
edited
Loading

Codecov Report

Merging #1526 into master will decrease coverage by 0.08%.
The diff coverage is n/a.

Impacted file tree graph

@@            Coverage Diff             @@
##           master    #1526      +/-   ##
==========================================
- Coverage   79.80%   79.71%   -0.09%     
==========================================
  Files         298      302       +4     
  Lines       11502    11678     +176     
  Branches     2475     2489      +14     
==========================================
+ Hits         9179     9309     +130     
- Misses       2323     2369      +46
Impacted Files Coverage Δ
...l_tests/aws-json/commands/EmptyOperationCommand.ts 90.00% <0.00%> (-10.00%) ⬇️
...ts/aws-query/commands/NoInputAndNoOutputCommand.ts 90.00% <0.00%> (-10.00%) ⬇️
.../aws-restxml/commands/NoInputAndNoOutputCommand.ts 90.00% <0.00%> (-10.00%) ⬇️
...aws-restjson/commands/NoInputAndNoOutputCommand.ts 90.00% <0.00%> (-10.00%) ⬇️
protocol_tests/aws-ec2/commands/XmlBlobsCommand.ts 95.00% <0.00%> (-5.00%) ⬇️
protocol_tests/aws-ec2/commands/XmlEnumsCommand.ts 95.00% <0.00%> (-5.00%) ⬇️
protocol_tests/aws-ec2/commands/XmlListsCommand.ts 95.00% <0.00%> (-5.00%) ⬇️
...rotocol_tests/aws-query/commands/XmlMapsCommand.ts 95.00% <0.00%> (-5.00%) ⬇️
...otocol_tests/aws-query/commands/XmlBlobsCommand.ts 95.00% <0.00%> (-5.00%) ⬇️
...otocol_tests/aws-query/commands/XmlEnumsCommand.ts 95.00% <0.00%> (-5.00%) ⬇️
... and 128 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 797ba7d...fe54abc. Read the comment docs.

@alexforsyth alexforsyth merged commit b6675b6 into aws:master Sep 15, 2020
@trivikr trivikr deleted the log-serde branch September 15, 2020 19:33
@github-actions
Copy link

This thread has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs and link to relevant comments in this thread.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Jan 16, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Reviewers

@AllanZhengYP AllanZhengYP AllanZhengYP approved these changes

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
4 participants
@trivikr @codecov-commenter @AllanZhengYP @alexforsyth