aws-sdk-js-v3: DynamoDBDocument can't unmarshall null

The fix is in https://github.com/aws/aws-sdk-js-v3/releases/tag/v3.224.0.

This issue has occurred since the nooplogger was added.

Previously the logger middleware didn’t run because logger.info wasn’t set, now that it is it crashes. That said the actual bug is when attempting to filter sensitive log information no check for null is in place.

This code works with 3.204.0 but crashes in 3.209.0

cat package.json
/tmp/dynamdb-null-issue ᐅ cat package.json
{
  "name": "dynamdb-null-issue",
  "version": "1.0.0",
  "description": "",
  "main": "index.js",
  "scripts": {
    "test": "echo \"Error: no test specified\" && exit 1"
  },
  "keywords": [],
  "author": "",
  "license": "Apache-2.0",
  "dependencies": {
    "@aws-sdk/client-dynamodb": "^3.210.0",
    "@aws-sdk/lib-dynamodb": "^3.210.0"
  }
}

cat index.mjs
import { DynamoDBClient } from '@aws-sdk/client-dynamodb'
import {
  DynamoDBDocumentClient,
  GetCommand,
  PutCommand
} from '@aws-sdk/lib-dynamodb'

const client = new DynamoDBClient({
  endpoint: 'http://localhost:8000',
  region: 'us-east-1',
  credentials: {
    accessKeyId: 'x',
    secretAccessKey: 'x'
  },
  // logger: null
})

const dynamodb = DynamoDBDocumentClient.from(client, {
  marshallOptions: {
    convertEmptyValues: false,
    removeUndefinedValues: true,
    convertClassInstanceToMap: false
  },
  unmarshallOptions: {
    wrapNumbers: false
  }
})

await dynamodb.send(
  new PutCommand({
    TableName: 'dynamodbStackTable',
    Item: {
      pk: 'null-issue',
      sk: 'null-issue',
      value: 'ok',
      null: null
    }
  })
)

const result = await dynamodb.send(
  new GetCommand({
    TableName: 'dynamodbStackTable',
    Key: {
      pk: 'null-issue',
      sk: 'null-issue'
    }
  })
)

console.log('result %s', JSON.stringify(result, null, 2))

/tmp/dynamdb-null-issue ᐅ node index.mjs
/private/tmp/dynamdb-null-issue/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1144
    if (obj.S !== undefined)
            ^

TypeError: Cannot read properties of null (reading 'S')
    at AttributeValueFilterSensitiveLog (/private/tmp/dynamdb-null-issue/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1144:13)
    at /private/tmp/dynamdb-null-issue/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1250:65
    at Array.reduce (<anonymous>)
    at GetItemOutputFilterSensitiveLog (/private/tmp/dynamdb-null-issue/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1248:40)
    at /private/tmp/dynamdb-null-issue/node_modules/@aws-sdk/middleware-logger/dist-cjs/loggerMiddleware.js:16:21
    at processTicksAndRejections (node:internal/process/task_queues:96:5)
    at async file:///private/tmp/dynamdb-null-issue/index.mjs:41:16

/tmp/dynamdb-null-issue ᐅ node index.mjs /private/tmp/dynamdb-null-issue/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1144 if (obj.S !== undefined) ^

TypeError: Cannot read properties of null (reading ‘S’) at AttributeValueFilterSensitiveLog (/private/tmp/dynamdb-null-issue/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1144:13) at /private/tmp/dynamdb-null-issue/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1250:65 at Array.reduce (<anonymous>) at GetItemOutputFilterSensitiveLog (/private/tmp/dynamdb-null-issue/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1248:40) at /private/tmp/dynamdb-null-issue/node_modules/@aws-sdk/middleware-logger/dist-cjs/loggerMiddleware.js:16:21 at processTicksAndRejections (node:internal/process/task_queues:96:5) at async file:///private/tmp/dynamdb-null-issue/index.mjs:41:16

Either downgrading to 3.204.0 or uncommenting the `logger: null` fixes the issue.

Hi @loganhersh ,

Thanks for the detailed explanation. Im finally able to verify that I’m getting the same exception.

Will discuss it with the dev team and will have someone take a look ASAP.

Repro Code:

import { GetCommand,DynamoDBDocumentClient } from "@aws-sdk/lib-dynamodb";
import { DynamoDBClient } from "@aws-sdk/client-dynamodb"

const ddbClient = new DynamoDBClient({region: "us-east-1"})

const marshallOptions = {
    convertEmptyValues: false,
    removeUndefinedValues: false,
    convertClassInstanceToMap: false,
};

const unmarshallOptions = {
    wrapNumbers: false,
};

const translateConfig = { marshallOptions, unmarshallOptions };

const ddbDocClient = DynamoDBDocumentClient.from(ddbClient, translateConfig);

// const putParams = {
//   TableName: "trobert2",
//   Item: {
//     id: "article:2074847",
//     sort: "language:en",
//     page_image: null ,
//   },
// };

// const put = async () => {
//   try {
//     const data = await ddbDocClient.send(new PutCommand(putParams));
//     console.log(data)
//     return data;
//   } catch (err) {
//     console.error(err);
//   }
// };
// put();

const getParams = {
  TableName: "trobert2",

  Key: {
    id: "article:2074847",
    sort: "language:en",
  },
};

const get = async () => {
  try {
    const response = await ddbDocClient.send(new GetCommand(getParams));
    if (!response || !response.Item) {
      return null;
    } else {
      console.log('Code Found:', response.Item);
      return response.Item;
    }
  } catch (err) {
    console.error(err);
    return null
  }
}
get();

Output

TypeError: Cannot read properties of null (reading 'S')
at AttributeValueFilterSensitiveLog (/test_folder/3846_dynamo_putItem_null/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1144:13)
    at /test_folder/3846_dynamo_putItem_null/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1230:128
    at Array.reduce (<anonymous>)
    at GetItemOutputFilterSensitiveLog (/test_folder/3846_dynamo_putItem_null/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1230:40)
    at /test_folder/3846_dynamo_putItem_null/node_modules/@aws-sdk/middleware-logger/dist-cjs/loggerMiddleware.js:16:21
    at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
    at async get (/test_folder/3846_dynamo_putItem_null/sample.js:32:22)

npm list:

test_folder/3846_dynamo_putItem_null
├── @aws-sdk/client-dynamodb@3.213.0
└── @aws-sdk/lib-dynamodb@3.213.0

We are also experiencing this issue though only as of 3.209.0, however it does seem to be the same problem that started this thread.

The core problem is that DynamoDBDocumentClient does not define its own outputFilterSensitiveLog function and so it uses the one defined in DynamoDBClient. That function is designed to handle marshalled records but when using DynamoDBDocumentClient, the records are already unmarshalled when this function is called. So it is essentially expecting a record like:

{
  "field1": { "S": "value1" },
  "field2": { "S": "value2" },
}

but it is getting:

{
  "field1": "value1",
  "field2": "value2",
}

Then when it tries to extract the value here it throws the error because it first tries to access obj.S where obj is now just the unmarshalled value of the field.

The error only occurs when the value is null because for any other value type, take a string for example: "value1".S is semantically valid. The result of this “double-unmarshalling” though is that all values for the dynamodb record appear as undefined. You can see this by providing a logger in the DynamoDBClient config and then executing a QueryCommand ensuring the records in the response have no null values (to prevent the error from occurring). The output looks like this:

{
  ...,
  output: {
    ...,
    Items: [
      {
        field1: undefined,
        field2: undefined,
      }
    ]
  }
}

The reason this has begun happening for certain people after 3.209.0 is because previously if you did not provide a logger, then the logger was set to an empty object. The logger middleware only invokes outputFilterSensitiveLog when typeof logger.info === "function", which previously wasn’t true because logger was an empty object. However, after this commit the logger now defaults to the NoOpLogger which defines the info function. So anyone who doesn’t provide their own logger will now be invoking the function that throws the error (i.e. the pre-existing bug originally reported in this issue).

TLDR: DynamoDBDocumentClient does not define it’s own logging filter functions and so it uses those that are defined by DynamoDBClient. Those filter functions effectively unmarshall the records and so they expect the records to be marshalled. The logging middleware which invokes those functions does so AFTER the document client has already unmarshalled the records and so the filter functions try to unmarshall AGAIN causing the error.

It seems like the document client needs to define its own filter functions that do not unmarshall the records since they will already be unmarshalled.

We are experiencing this same issue, using DynamoDB + DynamoDBDocument and the logger option. aws-sdk version 3.190.0. It appears to return the error on get of a property that is stored as NULL.

TypeError: Cannot read property 'S' of null
    at AttributeValueFilterSensitiveLog (/data/servers/project/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1144:13)
    at /data/servers/project/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1250:65
    at Array.reduce (<anonymous>)
    at GetItemOutputFilterSensitiveLog (/data/servers/project/node_modules/@aws-sdk/client-dynamodb/dist-cjs/models/models_0.js:1248:40)
    at /data/servers/project/node_modules/@aws-sdk/client-dynamodb/node_modules/@aws-sdk/middleware-logger/dist-cjs/loggerMiddleware.js:16:21

When I omit the logger option, or specifically the info child of the logger object I pass in, then the error disappears. So effectively we cannot enable the logger for DynamoDB queries.

Looking at AttributeValueFilterSensitiveLog, looks like it attempts to check for type properties of an object, without first checking if the object exists.

Hi everyone.

I apologize for the long wait times. We don’t comb through closed issues to see activity on it, the activity here got caught by some automation we had. If an issue persists after closing please open a new one

I’m still not able to reproduce this issue even when specifying a logger:

const ddbClient = new DynamoDBClient({
    region: "us-east-1",
    logger: {debug: (data)=>{console.log(data)}}
})

Can someone please upload a gist or a minimal repo with complete code for me to try and replicate this? Once we have this reproduced I can have the devs take a look.

Thanks, Ran~

hello everyone,

I’m proposing this be re-opened based on the new information I am about to share. this seems to still be an issue in version 3.172.0 which I have used for replication.

@RanVaknin I’m sorry, but I don’t really think there was actually new information requested in order to mark the ticket with response-requested.

That being said, I have identified the crux of the problem. It comes from ddbDocClient (or dynamodbDocClient in my case) and how that object has been created. All participants to this conversation (including myself) omitted this information so far.

  const dynamoDb = new DynamoDBClient({ region: AWS_REGION, logger: Logger })

  const dynamodbDocClient = DynamoDBDocumentClient.from(dynamoDb)

removing logger: Logger enables the code to run successfully. So I am assuming there are breaking changes added to that implementation (referring to the logger) that have been submitted since version higher than 3.154.0.

The logger implementation I am using is based on "winston": "3.8.2" I was able to replicate the issue with this simple logger:

import winston from 'winston'

const localLogger = winston.createLogger({})

@vbanderov, would you be so kind to also confirm that you also used a custom logger?

I would like to kindly ask for this issue to be re-opened. I think there should either be more information around the logger object that can be passed as configuration or more restrictions should be added to that type to ensure that this functions as it is expected.

Thank you and kind regards

I also don’t think this is the actual solution, but a dirty workaround. @JamesKyburz @loganhersh, I think you would have to set logger: undefined if you use typescript with strict checks. null won’t work.

@JamesKyburz I wouldn’t necessarily consider that a fix, but instead just a workaround. Also this is exactly what I said a few comments above.

This issue certainly needs re-opened and a proper fix applied since it shouldn’t be required to explicitly define a null logger and looking at the code in the clients, it doesn’t seem like that is a reliable workaround. Also these workarounds don’t help anyone that actually use the logger and can’t set it to null.

I would work on a PR to fix it but I don’t have the time at the moment. I’ll work on it in my free time, though I’m not sure when I will be able to finish it.

@RanVaknin I just hit this error and I am using the V3 of the document client (“3.154.0”).

export const getArticleNew = async (articleId: string, language: string): Promise<Record<string, any>> => {
  const response = await getDynamoDbDocumentClient().send(
    new GetCommand({
      Key: {
        id: `article:${articleId}`,
        sort: `language:${language}`
      },
      TableName: DYNAMODB_TABLE_NAME
    })
  )
  if (!response || !response.Item) {
    Logger.debug('no items')
    throw new Error(
      `no items found for article "${articleId}" in the "${language}" language`
    )
  }

  return response.Item
}

error:

TypeError: Cannot read properties of null (reading 'S')

after changing the Null field to a string, the code works fine. Failing document item:

{
  "id": {
    "S": "article:2074847"
  },
  "sort": {
    "S": "language:en"
  },
  "page_image": {
    "NULL": true
  }
}

EDIT: when reverting to version 3.131.0 the code works again:

"@aws-sdk/client-dynamodb": "3.137.0",
"@aws-sdk/lib-dynamodb": "3.137.0",

It appears to start failing with 3.141.0

@trobert2 @Victor-ARC Not sure if it helps in your cases, but you can also set the logger to an empty object: logger: {} in the DynamoDBClient config. The function that throws the error only gets called when logger.info is defined so in this case an empty object would work as well. Still just a workaround but it may be more compatible with strict ts usage than null.

Since DynamoDBClient and DynamoDBDocumentClient share the same sensitive log filter function, any actual solution would need to either change that function to conditionally unmarshall records, or they should not share that function and DynamoDBDocumentClient should define its own.

actually you cannot. The empty object does not satisfy the interface.

Please note the “if you use typescript with strict checks.” in my previous comment. You would have to provide an object implementing all the functions required to satisfy the interface OR undefined (as you can see in my previous comment’s screen shot).

@trobert2 @Victor-ARC Not sure if it helps in your cases, but you can also set the logger to an empty object: logger: {} in the DynamoDBClient config. The function that throws the error only gets called when logger.info is defined so in this case an empty object would work as well. Still just a workaround but it may be more compatible with strict ts usage than null.

Since DynamoDBClient and DynamoDBDocumentClient share the same sensitive log filter function, any actual solution would need to either change that function to conditionally unmarshall records, or they should not share that function and DynamoDBDocumentClient should define its own.

Can confirm this issue. My team and I are getting the same trace using the DynamoDBClient with version 3.209.0