Repository: dynamoosejs/dynamoose (js)

Issue:
Log/Debug Support
# Log/Debug Support

## Overview

In Dynamoose v1 we used [`debug`](https://www.npmjs.com/package/debug) for logging. It was suggested that we have a more custom solution that allows for more types of logging in Dynamoose. Which is a great idea.

Basically this system should be plug and play and super flexible and customizable.

## High Level Goals

- Ability to log to multiple systems (or log providers) (ex. ability to log to both `console.log` & `debug`)
- Ability for plugins or other packages to be able to provide custom logging system (or log providers) (ex. there should be a way to build a custom package that will take the logs and output them to a custom service)
- Ability to filter logs to only log certain information (ex. only log AWS requests or only log AWS responses)
- Ability to easily set simple logging (ex. `dynamoose.logger.set(console);` (or something like that) should be all you need to do to add debug logging). Of course it can get much more complex, but simple logging should be easy.

## Long Term Goals

- It'd be cool to build a plugin or something to be able to export logs directly to a GH issue so that users can prefill the template with logs, and it'll give us more insight into problems without having to request logs manually
- Maybe spin this off into a separate package so other packages/libraries can take advantage of this super flexible logging and debug system

## Other Information

- `console` support will be the only log provider built in by default, you can add more log providers through additional packages, or by building custom log providers for your application specifically

## Ideas for 3rd party log providers

- S3
- CloudWatch Logs
- HTTP Log Reporter (basically reporting logs to an HTTP service)
- `fs`
- [`debug`](https://www.npmjs.com/package/debug)
- [`winston`](https://www.npmjs.com/package/winston)

## Rough API Design

### dynamoose.logger.providers.set([logProviders])

This function will take in a log provider or an array of log providers and set the log providers to be that item or array of items (overwriting all existing log providers). And use it to output logs to those log providers.

```js
dynamoose.logger.set(console); // `console` is the only built in log provider by default
dynamoose.logger.set([console, new FSDynamooseLogger({logPath})]); // Will log to both `console` and `FSDynamooseLogger` with initialization options
dynamoose.logger.set({
    "id": "consoleLogger", // Custom id you set to be able to reference the log provider later, default is a random uuidv4 string
    "provider": console,
    "filter": {
        "level": "debug+", // This can either be an array of valid levels, or if `+` is at the end it will log all levels higher than the level or `-` to log all levels lower than the level
        "category": "aws:dynamodb:*:request" // This will filter to only log certain categories. You can use `*` to represent one section wildcard or `**` to represent unlimited wildcard
        // TODO: Add support for metadata based filtering
    }
});
```

### dynamoose.logger.providers.clear()

This function will revert all log providers to nothing so no logs are outputted. Same function as `dynamoose.logger.providers.set()` or `dynamoose.logger.providers.set([])`.

### dynamoose.logger.providers.add(logProvider)

This function will take in an log provider object or array of log provider objects and append it to the log providers used for logging.

### dynamoose.logger.providers.delete(id)

This function takes in an id of a log provider and will delete it from the log providers being used for logging.

### dynamoose.logger.providers.list()

This function will output a list of log providers being used.

### dynamoose.logger.pause()

This function will pause all logs being outputted to log providers.

### dynamoose.logger.resume()

This function will resume all logs being outputted to log providers.

### Example Custom Logger

```js
class FSDynamooseLogger {
    constructor(settings = {}) {
        this.settings = settings;
        this.type = "json";  // This can either be `json` or `string` to determine what style of logs to receive. (default: "json")
    }

    // This can either be a standard function or `async` function
    log(msg) {
        // You can also do additional filtering here to only log certain items based on the `msg` provided
        return fs.writeFile(path.join(this.settings.logPath, `${msg.id}.json`), msg, "utf8");
    }
}
```

### Log Message

A log provider can either set it up to accept strings or JSON objects. JSON objects will have more information about the specific log. And the format for JSON objects will look something like the following:

```js
{
    "id": "", // uuidv4 of the log
    "message": "", // A string based message of the log
    "level": "", // This can be one of the following: "fatal", "error", "warn", "info", "debug", "trace"
    "category": "aws:dynamodb:putItem:request" // This is a string separated by `:`'s related to the category of the log
    "metadata": {} // This is a custom object with metadata about the log. This can include things like the name of the Model, additional category information, or more.
    "timestamp": new Date() // A date instance of when the log was created
}
```

**level**:

- **fatal** - This is reserved for the most extreme errors
- **error** - Errors
- **warn** - Problems in the service, but where the service can likely recover from it gracefully
- **info** - High level messages about state of service that you might want to log more often than `debug` messages (ex. log about `dynamoose.aws.ddb.local()` being called and set successfully)
- **debug** - Information that would only be useful during debugging (ex. request & response payloads)
- **trace** - Information about internal functions or methods being called. This can help see the run up to a specific debug message. These messages can include things like `Document.prepareForObjectFromSchema called`.

Pull request:
Log/Debug Support
Closes #822

**TODO**

- Need to merge #798 into this PR to get one fix for the delete object utility to fix this branch
- Need to add some basic logging to Dynamoose (start with requests and responses from AWS DynamoDB)

Patch:
diff --git a/docs/api/General.md b/docs/api/General.md
index ff90a1f3..bbfc690e 100644
--- a/docs/api/General.md
+++ b/docs/api/General.md
@@ -102,6 +102,74 @@ This function is used to revert the `AWS.DynamoDB.Converter` instance that Dynam
 dynamoose.aws.converter.revert();
 ```
 
+## dynamoose.logger.providers.set([provider])
+
+This function allows you to set a provider(s) to receive logged events in Dynamoose. The `provider` parameter can either be a provider object, or an array of provider projects. This function will overwrite all existing providers set. If you pass `undefined`, `null`, or an empty array in as the `provider` parameter all existing providers will be removed. By default there are no providers setup with the Dynamoose logger.
+
+The simplest way to add logging to see what Dynamoose is doing under the hood is to run the following command. `console` is a specical internal log provider that can be used to print debug events to the console. You can also create custom log providers or find 3rd party plugin log providers for Dynamoose.
+
+```js
+dynamoose.logger.providers.set(console);
+```
+
+## dynamoose.logger.providers.clear()
+
+This function clears all existing log providers from Dynamooose. This function behaves the same as `dynamoose.logger.providers.set([])`.
+
+```js
+dynamoose.logger.providers.clear();
+```
+
+## dynamoose.logger.providers.add(provider)
+
+This function allows you to add a provider(s) to receive logged events in Dynamoose. The `provider` parameter can either be a provider object or an array of provider objects.
+
+Unlike `dynamoose.logger.providers.set` this function appends the new providers to the existing providers and does not overwrite any existing providers.
+
+```js
+dynamoose.logger.providers.add(console);
+```
+
+## dynamoose.logger.providers.delete(id)
+
+This function allows you to pass in an `id` parameter to delete an existing provider.
+
+```js
+dynamoose.logger.providers.delete(id);
+```
+
+## dynamoose.logger.providers.list()
+
+This function returns an array of all the log providers Dynamoose is currently using.
+
+```js
+dynamoose.logger.providers.list();
+```
+
+## dynamoose.logger.pause()
+
+This function pauses all output of log events to all log providers.
+
+```js
+dynamoose.logger.pause();
+```
+
+## dynamoose.logger.resume()
+
+This function resumes all output of log events to all log providers.
+
+```js
+dynamoose.logger.resume();
+```
+
+## dynamoose.logger.status()
+
+This function returns `active` if log events are being emitted to log providers, or `paused` if log events have been paused from being emitted to log providers.
+
+```js
+dynamoose.logger.status(); // "active" || "paused"
+```
+
 ## dynamoose.undefined
 
 Setting an attribute value to this will cause it to bypass the `default` value, and set it to `undefined` in the database.
diff --git a/lib/Document.js b/lib/Document.js
index b591c9be..7022e45d 100644
--- a/lib/Document.js
+++ b/lib/Document.js
@@ -1,4 +1,5 @@
 const aws = require("./aws");
+const ddb = require("./aws/ddb/internal");
 const utils = require("./utils");
 const Error = require("./Error");
 const {internalProperties} = require("./Internal").General;
@@ -168,7 +169,7 @@ function DocumentCarrier(model) {
 				}
 			} else {
 				// Check saveUnknown
-				if (!settings.saveUnknown || !utils.dynamoose.saveunknown_attribute_allowed_check(model.schema.getSettingValue("saveUnknown"), key)) {
+				if (!settings.saveUnknown || !utils.dynamoose.wildcard_allowed_check(model.schema.getSettingValue("saveUnknown"), key)) {
 					keysToDelete.push(key);
 				}
 			}
@@ -334,7 +335,7 @@ function DocumentCarrier(model) {
 		}
 		const promise = Promise.all([paramsPromise, Document.Model.pendingTaskPromise()]).then((promises) => {
 			const [putItemObj] = promises;
-			return aws.ddb().putItem(putItemObj).promise();
+			return ddb("putItem", putItemObj);
 		});
 
 		if (callback) {
diff --git a/lib/DocumentRetriever.js b/lib/DocumentRetriever.js
index 5e4cd339..8a966e86 100644
--- a/lib/DocumentRetriever.js
+++ b/lib/DocumentRetriever.js
@@ -1,4 +1,4 @@
-const aws = require("./aws");
+const ddb = require("./aws/ddb/internal");
 const Error = require("./Error");
 const utils = require("./utils");
 const Condition = require("./Condition");
@@ -168,10 +168,8 @@ function main(documentRetrieverTypeString) {
 				return array;
 			};
 			const promise = model.pendingTaskPromise().then(() => this[`get${utils.capitalize_first_letter(documentRetrieverType.type)}Request`]()).then((request) => {
-				const ddb = aws.ddb();
-
 				const allRequest = (extraParameters = {}) => {
-					let promise = ddb[documentRetrieverType.type]({...request, ...extraParameters}).promise();
+					let promise = ddb(documentRetrieverType.type, {...request, ...extraParameters});
 					timesRequested++;
 
 					if (this.settings.all) {
@@ -187,7 +185,7 @@ function main(documentRetrieverTypeString) {
 									await utils.timeout(this.settings.all.delay);
 								}
 
-								const nextRequest = await ddb[documentRetrieverType.type]({...request, ...extraParameters, "ExclusiveStartKey": lastKey}).promise();
+								const nextRequest = await ddb(documentRetrieverType.type, {...request, ...extraParameters, "ExclusiveStartKey": lastKey});
 								timesRequested++;
 								result = utils.merge_objects(result, nextRequest);
 								// The operation below is safe because right above we are overwriting the entire `result` variable, so there is no chance it'll be reassigned based on an outdated value since it's already been overwritten. There might be a better way to do this than ignoring the rule on the line below.
diff --git a/lib/Model/index.js b/lib/Model/index.js
index a10afb4d..0e51703e 100644
--- a/lib/Model/index.js
+++ b/lib/Model/index.js
@@ -3,7 +3,7 @@ const Schema = require("../Schema");
 const Document = require("../Document");
 const ModelStore = require("../ModelStore");
 const utils = require("../utils");
-const aws = require("../aws");
+const ddb = require("../aws/ddb/internal");
 const Internal = require("../Internal");
 const DocumentRetriever = require("../DocumentRetriever");
 const defaults = require("./defaults");
@@ -71,8 +71,7 @@ class Model {
 		// Run setup flow
 		const setupFlowPromise = setupFlow.reduce((existingFlow, flow) => {
 			return existingFlow.then(() => flow()).then((flow) => {
-				const flowItem = typeof flow === "function" ? flow : flow.promise;
-				return flowItem instanceof Promise ? flowItem : flowItem.bind(flow)();
+				return typeof flow === "function" ? flow() : flow;
 			});
 		}, Promise.resolve());
 		setupFlowPromise.then(() => this.ready = true).then(() => {this.pendingTasks.forEach((task) => task()); this.pendingTasks = [];});
@@ -135,10 +134,10 @@ class Model {
 // Utility functions
 async function createTable(model) {
 	if ((((await getTableDetails(model, {"allowError": true})) || {}).Table || {}).TableStatus === "ACTIVE") {
-		return {"promise": () => Promise.resolve()};
+		return () => Promise.resolve.bind(Promise)();
 	}
 
-	return aws.ddb().createTable(await createTableRequest(model));
+	return ddb("createTable", await createTableRequest(model));
 }
 async function createTableRequest(model) {
 	return {
@@ -147,43 +146,39 @@ async function createTableRequest(model) {
 		...await model.schema.getCreateTableAttributeParams(model)
 	};
 }
-function updateTimeToLive(model) {
-	return {
-		"promise": async () => {
-			let ttlDetails;
-
-			async function updateDetails() {
-				ttlDetails = await aws.ddb().describeTimeToLive({
-					"TableName": model.name
-				}).promise();
-			}
-			await updateDetails();
+async function updateTimeToLive(model) {
+	let ttlDetails;
 
-			function updateTTL() {
-				return aws.ddb().updateTimeToLive({
-					"TableName": model.name,
-					"TimeToLiveSpecification": {
-						"AttributeName": model.options.expires.attribute,
-						"Enabled": true
-					}
-				});
+	async function updateDetails() {
+		ttlDetails = await ddb("describeTimeToLive", {
+			"TableName": model.name
+		});
+	}
+	await updateDetails();
+
+	function updateTTL() {
+		return ddb("updateTimeToLive", {
+			"TableName": model.name,
+			"TimeToLiveSpecification": {
+				"AttributeName": model.options.expires.attribute,
+				"Enabled": true
 			}
+		});
+	}
 
-			switch (ttlDetails.TimeToLiveDescription.TimeToLiveStatus) {
-			case "DISABLING":
-				while (ttlDetails.TimeToLiveDescription.TimeToLiveStatus === "DISABLING") {
-					await utils.timeout(1000);
-					await updateDetails();
-				}
-				// fallthrough
-			case "DISABLED":
-				await updateTTL();
-				break;
-			default:
-				break;
-			}
+	switch (ttlDetails.TimeToLiveDescription.TimeToLiveStatus) {
+	case "DISABLING":
+		while (ttlDetails.TimeToLiveDescription.TimeToLiveStatus === "DISABLING") {
+			await utils.timeout(1000);
+			await updateDetails();
 		}
-	};
+		// fallthrough
+	case "DISABLED":
+		await updateTTL();
+		break;
+	default:
+		break;
+	}
 }
 function waitForActive(model) {
 	return () => new Promise((resolve, reject) => {
@@ -212,7 +207,7 @@ function waitForActive(model) {
 }
 async function getTableDetails(model, settings = {}) {
 	const func = async () => {
-		const tableDetails = await aws.ddb().describeTable({"TableName": model.name}).promise();
+		const tableDetails = await ddb("describeTable", {"TableName": model.name});
 		model.latestTableDetails = tableDetails; // eslint-disable-line require-atomic-updates
 	};
 	if (settings.forceRefresh || !model.latestTableDetails) {
@@ -232,14 +227,14 @@ async function updateTable(model) {
 	const expectedThroughput = utils.dynamoose.get_provisioned_throughput(model.options);
 	if ((expectedThroughput.BillingMode === currentThroughput.BillingMode && expectedThroughput.BillingMode) || ((currentThroughput.ProvisionedThroughput || {}).ReadCapacityUnits === (expectedThroughput.ProvisionedThroughput || {}).ReadCapacityUnits && currentThroughput.ProvisionedThroughput.WriteCapacityUnits === expectedThroughput.ProvisionedThroughput.WriteCapacityUnits)) {
 	// if ((expectedThroughput.BillingMode === currentThroughput.BillingModeSummary.BillingMode && expectedThroughput.BillingMode) || ((currentThroughput.ProvisionedThroughput || {}).ReadCapacityUnits === (expectedThroughput.ProvisionedThroughput || {}).ReadCapacityUnits && currentThroughput.ProvisionedThroughput.WriteCapacityUnits === expectedThroughput.ProvisionedThroughput.WriteCapacityUnits)) {
-		return {"promise": () => Promise.resolve()};
+		return () => Promise.resolve.bind(Promise)();
 	}
 
 	const object = {
 		"TableName": model.name,
 		...expectedThroughput
 	};
-	return aws.ddb().updateTable(object);
+	return ddb("updateTable", object);
 }
 
 function convertObjectToKey(key) {
@@ -283,7 +278,7 @@ Model.prototype.get = function (key, settings = {}, callback) {
 			return getItemParams;
 		}
 	}
-	const promise = this.pendingTaskPromise().then(() => aws.ddb().getItem(getItemParams).promise());
+	const promise = this.pendingTaskPromise().then(() => ddb("getItem", getItemParams));
 
 	if (callback) {
 		promise.then((response) => response.Item ? documentify(response.Item) : undefined).then((response) => callback(null, response)).catch((error) => callback(error));
@@ -338,7 +333,7 @@ Model.prototype.batchGet = function (keys, settings = {}, callback) {
 			return params;
 		}
 	}
-	const promise = this.pendingTaskPromise().then(() => aws.ddb().batchGetItem(params).promise());
+	const promise = this.pendingTaskPromise().then(() => ddb("batchGetItem", params));
 
 	if (callback) {
 		promise.then((response) => prepareResponse(response)).then((response) => callback(null, response)).catch((error) => callback(error));
@@ -393,7 +388,7 @@ Model.prototype.batchPut = function (items, settings = {}, callback) {
 			return paramsPromise;
 		}
 	}
-	const promise = this.pendingTaskPromise().then(() => paramsPromise).then((params) => aws.ddb().batchWriteItem(params).promise());
+	const promise = this.pendingTaskPromise().then(() => paramsPromise).then((params) => ddb("batchWriteItem", params));
 
 	if (callback) {
 		promise.then((response) => prepareResponse(response)).then((response) => callback(null, response)).catch((error) => callback(error));
@@ -574,7 +569,7 @@ Model.prototype.update = function (keyObj, updateObj, settings = {}, callback) {
 			return updateItemParamsPromise;
 		}
 	}
-	const promise = updateItemParamsPromise.then((params) => aws.ddb().updateItem(params).promise());
+	const promise = updateItemParamsPromise.then((params) => ddb("updateItem", params));
 
 	if (callback) {
 		promise.then((response) => response.Attributes ? documentify(response.Attributes) : undefined).then((response) => callback(null, response)).catch((error) => callback(error));
@@ -604,7 +599,7 @@ Model.prototype.delete = function (key, settings = {}, callback) {
 			return deleteItemParams;
 		}
 	}
-	const promise = this.pendingTaskPromise().then(() => aws.ddb().deleteItem(deleteItemParams).promise());
+	const promise = this.pendingTaskPromise().then(() => ddb("deleteItem", deleteItemParams));
 
 	if (callback) {
 		promise.then(() => callback()).catch((error) => callback(error));
@@ -648,7 +643,7 @@ Model.prototype.batchDelete = function (keys, settings = {}, callback) {
 			return params;
 		}
 	}
-	const promise = this.pendingTaskPromise().then(() => aws.ddb().batchWriteItem(params).promise());
+	const promise = this.pendingTaskPromise().then(() => ddb("batchWriteItem", params));
 
 	if (callback) {
 		promise.then((response) => prepareResponse(response)).then((response) => callback(null, response)).catch((error) => callback(error));
diff --git a/lib/Transaction.js b/lib/Transaction.js
index 137d7a8c..f61ff937 100644
--- a/lib/Transaction.js
+++ b/lib/Transaction.js
@@ -1,4 +1,4 @@
-const aws = require("./aws");
+const ddb = require("./aws/ddb/internal");
 const utils = require("./utils");
 const Error = require("./Error");
 const ModelStore = require("./ModelStore");
@@ -54,7 +54,7 @@ module.exports = (transactions, settings = {}, callback) => {
 		});
 		await Promise.all(models.map((model) => model.pendingTaskPromise()));
 
-		const result = await aws.ddb()[transactionType](transactionParams).promise();
+		const result = await ddb(transactionType, transactionParams);
 		return result.Responses ? await Promise.all(result.Responses.map((item, index) => {
 			const modelName = modelNames[index];
 			const model = models.find((model) => model.name === modelName);
diff --git a/lib/aws/ddb.js b/lib/aws/ddb/index.js
similarity index 80%
rename from lib/aws/ddb.js
rename to lib/aws/ddb/index.js
index bf9dc035..126e0703 100644
--- a/lib/aws/ddb.js
+++ b/lib/aws/ddb/index.js
@@ -1,13 +1,13 @@
 let customDDB;
 
 function main() {
-	const aws = require("./index");
+	const aws = require("../index");
 	return customDDB || new aws.sdk.DynamoDB();
 }
 main.set = (ddb) => customDDB = ddb;
 main.revert = () => customDDB = null;
 main.local = (endpoint = "http://localhost:8000") => {
-	const aws = require("./index");
+	const aws = require("../index");
 	main.set(new aws.sdk.DynamoDB({
 		endpoint
 	}));
diff --git a/lib/aws/ddb/internal.js b/lib/aws/ddb/internal.js
new file mode 100644
index 00000000..2befef7b
--- /dev/null
+++ b/lib/aws/ddb/internal.js
@@ -0,0 +1,9 @@
+const ddb = require("./index");
+const log = require("../../logger/emitter");
+
+module.exports = async (method, params) => {
+	log({"level": "debug", "category": `aws:dynamodb:${method}:request`, "message": JSON.stringify(params, null, 4), "payload": {"request": params}});
+	const result = await ddb()[method](params).promise();
+	log({"level": "debug", "category": `aws:dynamodb:${method}:response`, "message": typeof result === "undefined" ? "undefined" : JSON.stringify(result, null, 4), "payload": {"response": result}});
+	return result;
+};
diff --git a/lib/index.js b/lib/index.js
index 791aba83..85936f29 100644
--- a/lib/index.js
+++ b/lib/index.js
@@ -42,5 +42,6 @@ module.exports = {
 	"Condition": require("./Condition"),
 	"transaction": require("./Transaction"),
 	"aws": require("./aws"),
+	"logger": require("./logger"),
 	"undefined": Symbol("dynamoose.undefined")
 };
diff --git a/lib/logger/emitter.js b/lib/logger/emitter.js
new file mode 100644
index 00000000..5908df18
--- /dev/null
+++ b/lib/logger/emitter.js
@@ -0,0 +1,55 @@
+const status = require("./status");
+const providers = require("./providers");
+const Error = require("../Error");
+const utils = require("../utils");
+const uuid = require("uuid").v4;
+
+const validLevels = ["fatal", "error", "warn", "info", "debug", "trace"];
+
+module.exports = (event) => {
+	if (status.status() === "active") {
+		if (!event.message || !validLevels.includes(event.level)) {
+			throw new Error.InvalidParameter("You must pass in a valid message, level, and category into your event object.");
+		}
+
+		if (typeof event.category === "undefined" || event.category === null) {
+			event.category = "";
+		}
+
+		const ts = new Date();
+		providers.list().forEach((provider) => {
+			const emitProvider = provider.provider || provider;
+			if (provider.filter) {
+				if (provider.filter.level) {
+					if (Array.isArray(provider.filter.level)) {
+						if (!provider.filter.level.includes(event.level)) {
+							return;
+						}
+					} else {
+						if (provider.filter.level.endsWith("+") || provider.filter.level.endsWith("-")) {
+							const baseLevel = provider.filter.level.substring(0, provider.filter.level.length - 1);
+							const index = validLevels.findIndex((level) => level === baseLevel);
+							const newArray = validLevels.filter((a, i) => provider.filter.level.endsWith("+") ? i <= index : i >= index);
+							if (!newArray.includes(event.level)) {
+								return;
+							}
+						} else if (provider.filter.level !== event.level) {
+							return;
+						}
+					}
+				}
+				if (provider.filter.category) {
+					if (!utils.dynamoose.wildcard_allowed_check(Array.isArray(provider.filter.category) ? provider.filter.category : [provider.filter.category], event.category, {"splitString": ":", "prefixesDisallowed": false})) {
+						return;
+					}
+				}
+			}
+			emitProvider.log(emitProvider.type === "string" ? event.message : {
+				"id": uuid(),
+				"timestamp": ts,
+				"metadata": {},
+				...event
+			});
+		});
+	}
+};
diff --git a/lib/logger/index.js b/lib/logger/index.js
new file mode 100644
index 00000000..5618ac4b
--- /dev/null
+++ b/lib/logger/index.js
@@ -0,0 +1,7 @@
+const providers = require("./providers");
+const status = require("./status");
+
+module.exports = {
+	providers,
+	...status
+};
diff --git a/lib/logger/internal_providers/console.js b/lib/logger/internal_providers/console.js
new file mode 100644
index 00000000..50d4b5fc
--- /dev/null
+++ b/lib/logger/internal_providers/console.js
@@ -0,0 +1,25 @@
+class ConsoleProvider {
+	log(message) {
+		let method;
+		switch(message.level) {
+		case "fatal":
+		case "error":
+			method = console.error;
+			break;
+		case "warn":
+			method = console.warn;
+			break;
+		case "info":
+			method = console.info;
+			break;
+		case "debug":
+		case "trace":
+			method = console.log;
+			break;
+		}
+
+		method(message.category ? `${message.category} - ${message.message}` : message.message);
+	}
+}
+
+module.exports = ConsoleProvider;
diff --git a/lib/logger/internal_providers/index.js b/lib/logger/internal_providers/index.js
new file mode 100644
index 00000000..dcdb424e
--- /dev/null
+++ b/lib/logger/internal_providers/index.js
@@ -0,0 +1,3 @@
+module.exports = {
+	"console": require("./console")
+};
diff --git a/lib/logger/providers.js b/lib/logger/providers.js
new file mode 100644
index 00000000..a350b064
--- /dev/null
+++ b/lib/logger/providers.js
@@ -0,0 +1,41 @@
+const utils = require("../utils");
+const internalProviders = require("./internal_providers");
+let providers = [];
+
+// This method takes the provider and converts it to an internal provider if exists (ex. `console`)
+const normalizeProvider = (provider) => {
+	if (provider === console) {
+		return new internalProviders.console();
+	} else {
+		return provider;
+	}
+};
+
+module.exports = {
+	"set": (provider) => {
+		if (typeof provider === "undefined" || provider === null) {
+			provider = [];
+		}
+
+		providers = (Array.isArray(provider) ? provider : [provider]).map(normalizeProvider);
+	},
+	"clear": () => {
+		providers = [];
+	},
+	"add": (provider) => {
+		const newProviders = (Array.isArray(provider) ? provider : [provider]).map(normalizeProvider);
+		providers.push(...newProviders);
+	},
+	"delete": (id) => {
+		const deleteFunction = (id) => {
+			const index = providers.findIndex((provider) => provider.id === id);
+			utils.object.delete(providers, index);
+		};
+		if (Array.isArray(id)) {
+			id.forEach((id) => deleteFunction(id));
+		} else {
+			deleteFunction(id);
+		}
+	},
+	"list": () => providers
+};
diff --git a/lib/logger/status.js b/lib/logger/status.js
new file mode 100644
index 00000000..abf4ced6
--- /dev/null
+++ b/lib/logger/status.js
@@ -0,0 +1,13 @@
+let status = true; // Indicated if log events are being emitted to log providers or not
+
+module.exports = {
+	"pause": () => {
+		status = false;
+	},
+	"resume": () => {
+		status = true;
+	},
+	"status": () => {
+		return status ? "active" : "paused";
+	}
+};
diff --git a/lib/utils/dynamoose/index.js b/lib/utils/dynamoose/index.js
index f426d66e..662b3e70 100644
--- a/lib/utils/dynamoose/index.js
+++ b/lib/utils/dynamoose/index.js
@@ -1,4 +1,4 @@
 module.exports = {
-	"saveunknown_attribute_allowed_check": require("./saveunknown_attribute_allowed_check"),
+	"wildcard_allowed_check": require("./wildcard_allowed_check"),
 	"get_provisioned_throughput": require("./get_provisioned_throughput")
 };
diff --git a/lib/utils/dynamoose/saveunknown_attribute_allowed_check.js b/lib/utils/dynamoose/wildcard_allowed_check.js
similarity index 57%
rename from lib/utils/dynamoose/saveunknown_attribute_allowed_check.js
rename to lib/utils/dynamoose/wildcard_allowed_check.js
index cb9f0199..17cc5c86 100644
--- a/lib/utils/dynamoose/saveunknown_attribute_allowed_check.js
+++ b/lib/utils/dynamoose/wildcard_allowed_check.js
@@ -1,8 +1,8 @@
-module.exports = (saveUnknown, checkKey) => {
+module.exports = (saveUnknown, checkKey, settings = {"splitString": ".", "prefixesDisallowed": true}) => {
 	if (Array.isArray(saveUnknown)) {
 		return Boolean(saveUnknown.find((key) => {
-			const keyParts = key.split(".");
-			const checkKeyParts = checkKey.split(".");
+			const keyParts = key.split(settings.splitString);
+			const checkKeyParts = checkKey.split(settings.splitString);
 			let index = 0, keyPart = keyParts[0];
 			for (let i = 0; i < checkKeyParts.length; i++) {
 				if (keyPart === "**") {
@@ -13,6 +13,9 @@ module.exports = (saveUnknown, checkKey) => {
 				}
 				keyPart = keyParts[++index];
 			}
+			if (!settings.prefixesDisallowed && keyPart) {
+				return false;
+			}
 			return true;
 		}));
 	} else {
diff --git a/package-lock.json b/package-lock.json
index 77ed7c7c..6bdd1b02 100644
--- a/package-lock.json
+++ b/package-lock.json
@@ -450,6 +450,13 @@
         "url": "0.10.3",
         "uuid": "3.3.2",
         "xml2js": "0.4.19"
+      },
+      "dependencies": {
+        "uuid": {
+          "version": "3.3.2",
+          "resolved": "https://registry.npmjs.org/uuid/-/uuid-3.3.2.tgz",
+          "integrity": "sha512-yXJmeNaw3DnnKAOKJE51sL/ZaYfWJRl1pK9dr19YFCu0ObS231AB1/LbqTKRAQ5kw8A90rA6fr4riOUpTZvQZA=="
+        }
       }
     },
     "aws-sign2": {
@@ -2613,6 +2620,14 @@
         "tough-cookie": "~2.5.0",
         "tunnel-agent": "^0.6.0",
         "uuid": "^3.3.2"
+      },
+      "dependencies": {
+        "uuid": {
+          "version": "3.4.0",
+          "resolved": "https://registry.npmjs.org/uuid/-/uuid-3.4.0.tgz",
+          "integrity": "sha512-HjSDRw6gZE5JMggctHBcjVak08+KEVhSIiDzFnT9S9aegmp85S/bReBVTb4QTFaRNptJ9kuYaNhnbNEOkbKb/A==",
+          "dev": true
+        }
       }
     },
     "require-directory": {
@@ -3093,9 +3108,9 @@
       }
     },
     "uuid": {
-      "version": "3.3.2",
-      "resolved": "https://registry.npmjs.org/uuid/-/uuid-3.3.2.tgz",
-      "integrity": "sha512-yXJmeNaw3DnnKAOKJE51sL/ZaYfWJRl1pK9dr19YFCu0ObS231AB1/LbqTKRAQ5kw8A90rA6fr4riOUpTZvQZA=="
+      "version": "7.0.3",
+      "resolved": "https://registry.npmjs.org/uuid/-/uuid-7.0.3.tgz",
+      "integrity": "sha512-DPSke0pXhTZgoF/d+WSt2QaKMCFSfx7QegxEWT+JOuHF5aWrKEn0G+ztjuJg/gG8/ItK+rbPCD/yNv8yyih6Cg=="
     },
     "v8-compile-cache": {
       "version": "2.1.0",
diff --git a/package.json b/package.json
index f73ca137..7cf9dda2 100644
--- a/package.json
+++ b/package.json
@@ -38,7 +38,8 @@
     "url": "https://github.com/dynamoosejs/dynamoose/issues"
   },
   "dependencies": {
-    "aws-sdk": "^2.657.0"
+    "aws-sdk": "^2.657.0",
+    "uuid": "^7.0.3"
   },
   "license": "Unlicense",
   "keywords": [


Test patch:
diff --git a/test/Logger.js b/test/Logger.js
new file mode 100644
index 00000000..c5d9a4f4
--- /dev/null
+++ b/test/Logger.js
@@ -0,0 +1,372 @@
+const {expect} = require("chai");
+const dynamoose = require("../lib");
+const emitter = require("../lib/logger/emitter");
+
+describe("Logger", () => {
+	beforeEach(() => {
+		dynamoose.logger.providers.clear();
+		dynamoose.logger.resume();
+	});
+	afterEach(() => {
+		dynamoose.logger.providers.clear();
+	});
+
+	it("Should be an object", () => {
+		expect(dynamoose.logger).to.be.an("object");
+	});
+
+	describe("Status", () => {
+		describe("dynamoose.logger.status", () => {
+			it("Should be a function", () => {
+				expect(dynamoose.logger.status).to.be.a("function");
+			});
+
+			it("Should return paused if status is paused", () => {
+				dynamoose.logger.pause();
+				expect(dynamoose.logger.status()).to.eql("paused");
+			});
+
+			it("Should return active if status is paused", () => {
+				dynamoose.logger.resume();
+				expect(dynamoose.logger.status()).to.eql("active");
+			});
+		});
+
+		describe("dynamoose.logger.pause", () => {
+			it("Should be a function", () => {
+				expect(dynamoose.logger.pause).to.be.a("function");
+			});
+
+			it("Should set status to paused", () => {
+				dynamoose.logger.pause();
+				expect(dynamoose.logger.status()).to.eql("paused");
+			});
+		});
+
+		describe("dynamoose.logger.resume", () => {
+			it("Should be a function", () => {
+				expect(dynamoose.logger.resume).to.be.a("function");
+			});
+
+			it("Should set status to active", () => {
+				dynamoose.logger.resume();
+				expect(dynamoose.logger.status()).to.eql("active");
+			});
+		});
+	});
+
+	describe("dynamoose.logger.providers", () => {
+		it("Should be an object", () => {
+			expect(dynamoose.logger.providers).to.be.an("object");
+		});
+
+		describe("dynamoose.logger.providers.list", () => {
+			beforeEach(() => {
+				const obj = [{"id": "test"}];
+				dynamoose.logger.providers.set(obj);
+				expect(dynamoose.logger.providers.list()).to.eql(obj);
+			});
+
+			it("Should be a function", () => {
+				expect(dynamoose.logger.providers.list).to.be.a("function");
+			});
+
+			it("Should return list of providers", () => {
+				expect(dynamoose.logger.providers.list()).to.eql([{"id": "test"}]);
+			});
+		});
+
+		describe("dynamoose.logger.providers.set", () => {
+			it("Should be a function", () => {
+				expect(dynamoose.logger.providers.set).to.be.a("function");
+			});
+
+			it("Should set correctly for object", () => {
+				const obj = {"id": "test"};
+				dynamoose.logger.providers.set(obj);
+				expect(dynamoose.logger.providers.list()).to.eql([obj]);
+			});
+
+			it("Should set correctly for array", () => {
+				const obj = [{"id": "test"}];
+				dynamoose.logger.providers.set(obj);
+				expect(dynamoose.logger.providers.list()).to.eql(obj);
+			});
+
+			it("Should set correctly for empty array", () => {
+				const originalProviders = dynamoose.logger.providers.list();
+				const obj = [];
+				dynamoose.logger.providers.set(obj);
+				expect(dynamoose.logger.providers.list()).to.eql(obj);
+				expect(dynamoose.logger.providers.list()).to.eql(originalProviders);
+			});
+
+			it("Should set correctly for nothing passed in", () => {
+				const originalProviders = dynamoose.logger.providers.list();
+				dynamoose.logger.providers.set();
+				expect(dynamoose.logger.providers.list()).to.eql([]);
+				expect(dynamoose.logger.providers.list()).to.eql(originalProviders);
+			});
+
+			it("Should set correctly for undefined passed in", () => {
+				const originalProviders = dynamoose.logger.providers.list();
+				dynamoose.logger.providers.set(undefined);
+				expect(dynamoose.logger.providers.list()).to.eql([]);
+				expect(dynamoose.logger.providers.list()).to.eql(originalProviders);
+			});
+
+			it("Should set correctly for null passed in", () => {
+				const originalProviders = dynamoose.logger.providers.list();
+				dynamoose.logger.providers.set(null);
+				expect(dynamoose.logger.providers.list()).to.eql([]);
+				expect(dynamoose.logger.providers.list()).to.eql(originalProviders);
+			});
+		});
+
+		describe("dynamoose.logger.providers.clear", () => {
+			beforeEach(() => {
+				const obj = [{"id": "test"}];
+				dynamoose.logger.providers.set(obj);
+				expect(dynamoose.logger.providers.list()).to.eql(obj);
+			});
+
+			it("Should be a function", () => {
+				expect(dynamoose.logger.providers.clear).to.be.a("function");
+			});
+
+			it("Should set providers to empty array", () => {
+				dynamoose.logger.providers.clear();
+				expect(dynamoose.logger.providers.list()).to.eql([]);
+			});
+		});
+
+		describe("dynamoose.logger.providers.add", () => {
+			beforeEach(() => {
+				const obj = [{"id": "test"}];
+				dynamoose.logger.providers.set(obj);
+				expect(dynamoose.logger.providers.list()).to.eql(obj);
+			});
+
+			it("Should be a function", () => {
+				expect(dynamoose.logger.providers.add).to.be.a("function");
+			});
+
+			it("Should add object provider to providers", () => {
+				dynamoose.logger.providers.add({"id": "test2"});
+				expect(dynamoose.logger.providers.list()).to.eql([{"id": "test"}, {"id": "test2"}]);
+			});
+
+			it("Should add array of providers to providers", () => {
+				dynamoose.logger.providers.add([{"id": "test2"}, {"id": "test3"}]);
+				expect(dynamoose.logger.providers.list()).to.eql([{"id": "test"}, {"id": "test2"}, {"id": "test3"}]);
+			});
+		});
+
+		describe("dynamoose.logger.providers.delete", () => {
+			beforeEach(() => {
+				const obj = [{"id": "test"}, {"id": "test2"}, {"id": "test3"}];
+				dynamoose.logger.providers.set(obj);
+				expect(dynamoose.logger.providers.list()).to.eql(obj);
+			});
+
+			it("Should be a function", () => {
+				expect(dynamoose.logger.providers.delete).to.be.a("function");
+			});
+
+			it("Should delete provider", () => {
+				dynamoose.logger.providers.delete("test2");
+				expect(dynamoose.logger.providers.list()).to.eql([{"id": "test"}, {"id": "test3"}]);
+			});
+
+			it("Should delete multiple providers if array passed into delete", () => {
+				dynamoose.logger.providers.delete(["test2", "test3"]);
+				expect(dynamoose.logger.providers.list()).to.eql([{"id": "test"}]);
+			});
+		});
+	});
+
+	describe("Emitter", () => {
+		let events = [];
+		class CustomProvider {
+			log(event) {
+				events.push(event);
+			}
+		}
+		class CustomProviderMessage {
+			constructor() {
+				this.type = "string";
+			}
+			log(event) {
+				events.push(event);
+			}
+		}
+		beforeEach(() => {
+			dynamoose.logger.providers.set(new CustomProvider());
+		});
+		afterEach(() => {
+			events = [];
+		});
+
+		it("Should log event", () => {
+			emitter({"level": "info", "message": "Hello World", "category": "test"});
+			expect(events).to.be.an("array");
+			expect(events.length).to.eql(1);
+			expect(events[0]).to.be.an("object");
+			expect(Object.keys(events[0]).sort()).to.eql(["id", "timestamp", "level", "message", "category", "metadata"].sort());
+			expect(events[0].id).to.be.a("string");
+			expect(events[0].id).to.not.eql("");
+			expect(events[0].timestamp).to.be.within(new Date(Date.now() - 2000), new Date(Date.now() + 2000));
+			expect(events[0].level).to.eql("info");
+			expect(events[0].message).to.eql("Hello World");
+			expect(events[0].category).to.eql("test");
+			expect(events[0].metadata).to.eql({});
+		});
+
+		it("Should log event with string type", () => {
+			dynamoose.logger.providers.set(new CustomProviderMessage());
+			emitter({"level": "info", "message": "Hello World", "category": "test"});
+			expect(events).to.eql(["Hello World"]);
+		});
+
+		it("Should allow for no category", () => {
+			emitter({"level": "info", "message": "Hello World"});
+			expect(events[0].category).to.eql("");
+		});
+
+		it("Should not log event if paused", () => {
+			dynamoose.logger.pause();
+			emitter({"level": "info", "message": "Hello World", "category": "test"});
+			expect(events.length).to.eql(0);
+		});
+
+		it("Should throw error if no message passed in", () => {
+			expect(() => emitter({"level": "info"})).to.throw("You must pass in a valid message, level, and category into your event object.");
+		});
+
+		it("Should throw error if no level passed in", () => {
+			expect(() => emitter({"message": "Hello World"})).to.throw("You must pass in a valid message, level, and category into your event object.");
+		});
+
+		it("Should throw error if invalid level passed in", () => {
+			expect(() => emitter({"message": "Hello World", "level": "random"})).to.throw("You must pass in a valid message, level, and category into your event object.");
+		});
+
+		describe("Filter", () => {
+			describe("Level", () => {
+				const tests = [
+					{"filter": "error", "level": "error", "outcome": false},
+					{"filter": "error", "level": "fatal", "outcome": true},
+					{"filter": "error+", "level": "fatal", "outcome": false},
+					{"filter": "error+", "level": "error", "outcome": false},
+					{"filter": "error+", "level": "debug", "outcome": true},
+					{"filter": "error-", "level": "fatal", "outcome": true},
+					{"filter": "error-", "level": "error", "outcome": false},
+					{"filter": "error-", "level": "debug", "outcome": false},
+					{"filter": ["error", "info"], "level": "error", "outcome": false},
+					{"filter": ["error", "info"], "level": "info", "outcome": false},
+					{"filter": ["error", "info"], "level": "fatal", "outcome": true},
+				];
+				tests.forEach((test) => {
+					it(`Should ${test.outcome ? "" : "not "}filter level ${typeof test.filter === "object" ? JSON.stringify(test.filter) : `"${test.filter}"`} for input of ${test.level}`, () => {
+						dynamoose.logger.providers.set({
+							"provider": new CustomProvider(),
+							"filter": {
+								"level": test.filter
+							}
+						});
+						emitter({"level": test.level, "message": "Hello World"});
+						expect(events.length).to.eql(test.outcome ? 0 : 1);
+					});
+				});
+			});
+
+			describe("Category", () => {
+				const tests = [
+					{"filter": "aws:dynamodb:putItem:request", "category": "aws:dynamodb:putItem:request", "outcome": false},
+					{"filter": "aws:dynamodb:putItem:request", "category": "aws:dynamodb:putItem:response", "outcome": true},
+					{"filter": ["aws:dynamodb:putItem:request", "aws:dynamodb:putItem:response"], "category": "aws:dynamodb:putItem:response", "outcome": false},
+					{"filter": "*:dynamodb:putItem:request", "category": "aws:dynamodb:putItem:request", "outcome": false},
+					{"filter": "*:dynamodb:putItem:request", "category": "aws:dynamodb:putItem:request", "outcome": false},
+					{"filter": "**", "category": "aws:dynamodb:putItem:request", "outcome": false},
+					{"filter": "*:dynamodb:putItem:request", "category": "aws:dynamodb:getItem:request", "outcome": true},
+					{"filter": "*:dynamodb:**", "category": "aws:dynamodb:getItem:request", "outcome": false},
+					{"filter": "*:dynamodb:**", "category": "aws:dynamodb:getItem:response", "outcome": false},
+					{"filter": "*:dynamodb:**", "category": "aws:dynamodb:putItem:request", "outcome": false},
+					{"filter": "*:dynamodb:**", "category": "aws:dynamodb:putItem:response", "outcome": false},
+					{"filter": "random", "category": "other", "outcome": true},
+					{"filter": "random:*", "category": "other", "outcome": true},
+					{"filter": "random:*", "category": "random", "outcome": true},
+					{"filter": "random:**", "category": "random", "outcome": true},
+					{"filter": "random:*:test", "category": "random:test", "outcome": true},
+				];
+				tests.forEach((test) => {
+					it(`Should ${test.outcome ? "" : "not "}filter level ${typeof test.filter === "object" ? JSON.stringify(test.filter) : `"${test.filter}"`} for input of ${test.category}`, () => {
+						dynamoose.logger.providers.set({
+							"provider": new CustomProvider(),
+							"filter": {
+								"category": test.filter
+							}
+						});
+						emitter({"level": "error", "category": test.category, "message": "Hello World"});
+						expect(events.length).to.eql(test.outcome ? 0 : 1);
+					});
+				});
+			});
+		});
+	});
+
+	describe("Console Logger", () => {
+		const consoleTypes = ["error", "warn", "info", "log"];
+		let logs = [];
+		let originalConsole = {};
+		beforeEach(() => {
+			dynamoose.logger.providers.set(console);
+			consoleTypes.forEach((type) => {
+				originalConsole[type] = console[type];
+				console[type] = (str) => logs.push({"message": str, type});
+			});
+		});
+		afterEach(() => {
+			consoleTypes.forEach((type) => {
+				console[type] = originalConsole[type];
+			});
+			originalConsole = {};
+			logs = [];
+		});
+
+		it("Should print message & category", () => {
+			emitter({"level": "fatal", "message": "Hello World", "category": "test"});
+			expect(logs).to.eql([{"message": "test - Hello World", "type": "error"}]);
+		});
+
+		it("Should print message to console.error for fatal", () => {
+			emitter({"level": "fatal", "message": "Hello World"});
+			expect(logs).to.eql([{"message": "Hello World", "type": "error"}]);
+		});
+
+		it("Should print message to console.error for error", () => {
+			emitter({"level": "error", "message": "Hello World"});
+			expect(logs).to.eql([{"message": "Hello World", "type": "error"}]);
+		});
+
+		it("Should print message to console.warn for warn", () => {
+			emitter({"level": "warn", "message": "Hello World"});
+			expect(logs).to.eql([{"message": "Hello World", "type": "warn"}]);
+		});
+
+		it("Should print message to console.info for info", () => {
+			emitter({"level": "info", "message": "Hello World"});
+			expect(logs).to.eql([{"message": "Hello World", "type": "info"}]);
+		});
+
+		it("Should print message to console.log for debug", () => {
+			emitter({"level": "debug", "message": "Hello World"});
+			expect(logs).to.eql([{"message": "Hello World", "type": "log"}]);
+		});
+
+		it("Should print message to console.log for trace", () => {
+			emitter({"level": "trace", "message": "Hello World"});
+			expect(logs).to.eql([{"message": "Hello World", "type": "log"}]);
+		});
+	});
+});
diff --git a/test/Model.js b/test/Model.js
index 675db45d..5ce09554 100644
--- a/test/Model.js
+++ b/test/Model.js
@@ -448,7 +448,7 @@ describe("Model", () => {
 					"updateTable": (params) => {
 						updateTableParams.push(params);
 						return {
-							"promise": Promise.resolve()
+							"promise": () => Promise.resolve()
 						};
 					}
 				});
@@ -563,7 +563,7 @@ describe("Model", () => {
 					"updateTimeToLive": (params) => {
 						updateTTLParams.push(params);
 						return {
-							"promise": Promise.resolve()
+							"promise": () => Promise.resolve()
 						};
 					},
 					"describeTimeToLive": () => {
diff --git a/test/utils/dynamoose/saveunknown_attribute_allowed_check.js b/test/utils/dynamoose/wildcard_allowed_check.js
similarity index 87%
rename from test/utils/dynamoose/saveunknown_attribute_allowed_check.js
rename to test/utils/dynamoose/wildcard_allowed_check.js
index f04db16e..0b112dc2 100644
--- a/test/utils/dynamoose/saveunknown_attribute_allowed_check.js
+++ b/test/utils/dynamoose/wildcard_allowed_check.js
@@ -1,9 +1,9 @@
 const {expect} = require("chai");
 const utils = require("../../../lib/utils");
 
-describe("utils.dynamoose.saveunknown_attribute_allowed_check", () => {
+describe("utils.dynamoose.wildcard_allowed_check", () => {
 	it("Should be a function", () => {
-		expect(utils.dynamoose.saveunknown_attribute_allowed_check).to.be.a("function");
+		expect(utils.dynamoose.wildcard_allowed_check).to.be.a("function");
 	});
 
 	const tests = [
@@ -92,7 +92,7 @@ describe("utils.dynamoose.saveunknown_attribute_allowed_check", () => {
 
 	tests.forEach((test) => {
 		it(`Should return ${test.output} for ${test.input}`, () => {
-			expect(utils.dynamoose.saveunknown_attribute_allowed_check(...test.input)).to.eql(test.output);
+			expect(utils.dynamoose.wildcard_allowed_check(...test.input)).to.eql(test.output);
 		});
 	});
 });