Updated Tutorial (markdown)
Shinwoo PARK
parent
4b45b9d558
commit
2badacbbed
237
Tutorial.md
237
Tutorial.md
@ -621,3 +621,240 @@ It's little longer than before, but you can easily see the flow.
|
|||||||
But it's still hard to see the **single** flow.
|
But it's still hard to see the **single** flow.
|
||||||
|
|
||||||
For instance, if user 'a' and 'b' simultaneously call `/register` endpoint, it will be confusing to read only user `a`'s log.
|
For instance, if user 'a' and 'b' simultaneously call `/register` endpoint, it will be confusing to read only user `a`'s log.
|
||||||
|
|
||||||
|
### Adding a Scope Key
|
||||||
|
|
||||||
|
We made additional solution for this, recently.
|
||||||
|
The **Scoped Key**.
|
||||||
|
|
||||||
|
You can add scoped key using `ScopeKey` decorator.
|
||||||
|
|
||||||
|
```ts
|
||||||
|
// ...
|
||||||
|
@LoggedRoute()
|
||||||
|
@Post('register')
|
||||||
|
async userRegistration(
|
||||||
|
@LoggedParam('data', { excludePath: ['password'] })
|
||||||
|
@ScopeKey('username', { path: ['username'] }) // add this!
|
||||||
|
@Body()
|
||||||
|
data: RegistrationBody,
|
||||||
|
@InjectLogger logger: ScopedLogger,
|
||||||
|
): Promise<void> {
|
||||||
|
if (
|
||||||
|
(await this.appService.checkUsernameDuplication(data.username, logger)) ||
|
||||||
|
(await this.appService.checkEmailDuplication(data.email, logger))
|
||||||
|
) {
|
||||||
|
logger.error('Duplicated data!!');
|
||||||
|
throw new BadRequestException('Duplicated User');
|
||||||
|
}
|
||||||
|
|
||||||
|
logger.log('Now calling addUser..');
|
||||||
|
await this.appService.addUser(data, logger);
|
||||||
|
}
|
||||||
|
// ...
|
||||||
|
```
|
||||||
|
|
||||||
|
```sh
|
||||||
|
$ curl -X POST http://localhost:3000/register -d "{\"username\": \"A\", \"password\": \"SuperSecret\", \"email\": \"NestLogged@worplo.com\"}" -H "Content-Type: application/json"
|
||||||
|
```
|
||||||
|
|
||||||
|
```md
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): HIT HTTP AppController::register[POST] (userRegistration) WITH data={"username":"A","email":"NestLogged@worplo.com"}
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): -> checkUsernameDuplication: CALL checkUsernameDuplication WITH username=A
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): -> checkUsernameDuplication: There is no duplication!
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): -> checkUsernameDuplication: RETURNED checkUsernameDuplication
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): -> checkEmailDuplication: CALL checkEmailDuplication WITH email=NestLogged@worplo.com
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): -> checkEmailDuplication: There is no duplication!
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): -> checkEmailDuplication: RETURNED checkEmailDuplication
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): Now calling addUser..
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): -> addUser: CALL addUser WITH data={"username":"A","email":"NestLogged@worplo.com"}
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): -> addUser: Now creating a new user...
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): -> addUser: RETURNED addUser
|
||||||
|
[Nest] 2950529 - 12/10/2023, 8:51:46 PM LOG [AppController] -> userRegistration(username=A): RETURNED RESPONSE AppController::register[POST] (userRegistration)
|
||||||
|
```
|
||||||
|
|
||||||
|
Now, even if user `A` and `B` calls backend at the same time, we can recognize what is user `A`'s log!
|
||||||
|
|
||||||
|
### Scope Key Advanced Technique
|
||||||
|
|
||||||
|
We made `ScopeKey` decorator dynamically, to useful in almost every situation.
|
||||||
|
|
||||||
|
For example, it easily handles OR.
|
||||||
|
|
||||||
|
Let's pick a method from our test cases.
|
||||||
|
|
||||||
|
```ts
|
||||||
|
// ...
|
||||||
|
@LoggedFunction
|
||||||
|
async testOrScopedLogging(
|
||||||
|
@LoggedParam("key")
|
||||||
|
@ScopeKey("scopekey-a", { path: "a" })
|
||||||
|
@ScopeKey("scopekey-b", { path: "b" })
|
||||||
|
key: { a: string } | { b: string },
|
||||||
|
@InjectLogger logger?: ScopedLogger
|
||||||
|
) {
|
||||||
|
logger.log(JSON.stringify(key));
|
||||||
|
}
|
||||||
|
// ...
|
||||||
|
|
||||||
|
tester.testOrScopedLogging({ a: "asdf" });
|
||||||
|
tester.testOrScopedLogging({ b: "qwer" });
|
||||||
|
```
|
||||||
|
|
||||||
|
Log:
|
||||||
|
|
||||||
|
```md
|
||||||
|
[Nest] 2999438 - 12/10/2023, 9:00:27 PM LOG [LoggedMethodsClass] -> testOrScopedLogging(scopekey-a=asdf): CALL testOrScopedLogging WITH key={"a":"asdf"}
|
||||||
|
[Nest] 2999438 - 12/10/2023, 9:00:27 PM LOG [LoggedMethodsClass] -> testOrScopedLogging(scopekey-a=asdf): {"a":"asdf"}
|
||||||
|
[Nest] 2999438 - 12/10/2023, 9:00:27 PM LOG [LoggedMethodsClass] -> testOrScopedLogging(scopekey-b=qwer): CALL testOrScopedLogging WITH key={"b":"qwer"}
|
||||||
|
[Nest] 2999438 - 12/10/2023, 9:00:27 PM LOG [LoggedMethodsClass] -> testOrScopedLogging(scopekey-b=qwer): {"b":"qwer"}
|
||||||
|
[Nest] 2999438 - 12/10/2023, 9:00:27 PM LOG [LoggedMethodsClass] -> testOrScopedLogging(scopekey-a=asdf): RETURNED testOrScopedLogging
|
||||||
|
[Nest] 2999438 - 12/10/2023, 9:00:27 PM LOG [LoggedMethodsClass] -> testOrScopedLogging(scopekey-b=qwer): RETURNED testOrScopedLogging
|
||||||
|
```
|
||||||
|
|
||||||
|
If there is multiple ScopeKey decorator, it will try every single time, and only filter successful ones, and then select one by priority.
|
||||||
|
|
||||||
|
You can give a priority in option.
|
||||||
|
|
||||||
|
There is another test case that is simply illustrate the priority system.
|
||||||
|
|
||||||
|
```ts
|
||||||
|
// ...
|
||||||
|
@LoggedFunction
|
||||||
|
async testPriorityScopedLogging(
|
||||||
|
@LoggedParam("key")
|
||||||
|
@ScopeKey("scopekey-a", { path: "a", priority: 0.5 })
|
||||||
|
@ScopeKey("scopekey-b", { path: "b" }) // default 1
|
||||||
|
key: { a?: string; b?: string },
|
||||||
|
// if both a and b are undefined, set scope to nothing
|
||||||
|
@InjectLogger logger?: ScopedLogger
|
||||||
|
) {
|
||||||
|
logger.log(JSON.stringify(key));
|
||||||
|
}
|
||||||
|
// ...
|
||||||
|
|
||||||
|
tester.testPriorityScopedLogging({ a: "asdf", b: "qwer" });
|
||||||
|
tester.testPriorityScopedLogging({ a: "asdf" });
|
||||||
|
tester.testPriorityScopedLogging({ b: "qwer" });
|
||||||
|
tester.testPriorityScopedLogging({});
|
||||||
|
```
|
||||||
|
|
||||||
|
```md
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): CALL testPriorityScopedLogging WITH key={"a":"asdf","b":"qwer"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): {"a":"asdf","b":"qwer"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-a=asdf): CALL testPriorityScopedLogging WITH key={"a":"asdf"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-a=asdf): {"a":"asdf"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): CALL testPriorityScopedLogging WITH key={"b":"qwer"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): {"b":"qwer"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging: CALL testPriorityScopedLogging WITH key={}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging: {}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): RETURNED testPriorityScopedLogging
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-a=asdf): RETURNED testPriorityScopedLogging
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): RETURNED testPriorityScopedLogging
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging: RETURNED testPriorityScopedLogging
|
||||||
|
```
|
||||||
|
|
||||||
|
This is called asynchronously, so it's little massive, but still can find the flow.
|
||||||
|
|
||||||
|
Let's sort it.
|
||||||
|
|
||||||
|
`First call with {"a": "asdf", "b": "qwer"}`
|
||||||
|
```md
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): CALL testPriorityScopedLogging WITH key={"a":"asdf","b":"qwer"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): {"a":"asdf","b":"qwer"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): RETURNED testPriorityScopedLogging
|
||||||
|
```
|
||||||
|
|
||||||
|
`Second call with {"a": "asdf"}`
|
||||||
|
```md
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-a=asdf): CALL testPriorityScopedLogging WITH key={"a":"asdf"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-a=asdf): {"a":"asdf"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-a=asdf): RETURNED testPriorityScopedLogging
|
||||||
|
```
|
||||||
|
|
||||||
|
`Third call with {"b": "qwer"}`
|
||||||
|
```md
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): CALL testPriorityScopedLogging WITH key={"b":"qwer"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): {"b":"qwer"}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging(scopekey-b=qwer): RETURNED testPriorityScopedLogging
|
||||||
|
```
|
||||||
|
|
||||||
|
`Fourth call with {}`
|
||||||
|
```md
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging: CALL testPriorityScopedLogging WITH key={}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging: {}
|
||||||
|
[Nest] 3014294 - 12/10/2023, 9:03:37 PM LOG [LoggedMethodsClass] -> testPriorityScopedLogging: RETURNED testPriorityScopedLogging
|
||||||
|
```
|
||||||
|
|
||||||
|
See the function definition first.
|
||||||
|
There is a two ScopeKey decorator. first is named "scopekey-a", path is "a", and priority is 0.5.
|
||||||
|
Second one is named "scopekey-b", path is "b", and priority is not provided but default is 1.
|
||||||
|
|
||||||
|
So, in the first call, both of them are existed but the scopekey-b was chosen, because the priority was bigger than scopekey-a.
|
||||||
|
|
||||||
|
But there is no value in scopekey-b path, it will choose scopekey-a as the scope key.
|
||||||
|
|
||||||
|
If there is nothing, no scope key will be chosen, no error occurred.
|
||||||
|
|
||||||
|
When you need some debugging (warning when there is no scope key chosen), you can use `ShouldScoped` function decorator.
|
||||||
|
|
||||||
|
```ts
|
||||||
|
// ...
|
||||||
|
@LoggedFunction
|
||||||
|
@ShouldScoped // Warn if there is no valid scopekey
|
||||||
|
async testShouldScopedLogging(
|
||||||
|
@LoggedParam("key")
|
||||||
|
@ScopeKey("scopekey")
|
||||||
|
key?: string,
|
||||||
|
@InjectLogger logger?: ScopedLogger
|
||||||
|
) {
|
||||||
|
logger.log(key);
|
||||||
|
}
|
||||||
|
// ...
|
||||||
|
tester.testShouldScopedLogging("asdf");
|
||||||
|
tester.testShouldScopedLogging();
|
||||||
|
```
|
||||||
|
|
||||||
|
```md
|
||||||
|
[Nest] 3069515 - 12/10/2023, 9:15:14 PM LOG [LoggedMethodsClass] -> testShouldScopedLogging(scopekey=asdf): CALL testShouldScopedLogging WITH key=asdf
|
||||||
|
[Nest] 3069515 - 12/10/2023, 9:15:14 PM LOG [LoggedMethodsClass] -> testShouldScopedLogging(scopekey=asdf): asdf
|
||||||
|
[Nest] 3069515 - 12/10/2023, 9:15:14 PM LOG [LoggedMethodsClass] -> testShouldScopedLogging(scopekey=asdf): RETURNED testShouldScopedLogging
|
||||||
|
|
||||||
|
|
||||||
|
[Nest] 3069515 - 12/10/2023, 9:15:14 PM WARN [LoggedMethodsClass] -> testShouldScopedLogging: ScopeKey in ShouldScope cannot be falsy value (undefined)
|
||||||
|
[Nest] 3069515 - 12/10/2023, 9:15:14 PM LOG [LoggedMethodsClass] -> testShouldScopedLogging: CALL testShouldScopedLogging WITH key=undefined
|
||||||
|
[Nest] 3069515 - 12/10/2023, 9:15:14 PM LOG [LoggedMethodsClass] -> testShouldScopedLogging: undefined
|
||||||
|
[Nest] 3069515 - 12/10/2023, 9:15:14 PM LOG [LoggedMethodsClass] -> testShouldScopedLogging: RETURNED testShouldScopedLogging
|
||||||
|
```
|
||||||
|
|
||||||
|
As you can see, it's warning you about falsy value of scope key, but it's not error.
|
||||||
|
It will not block you for falsy value, or not existing value.
|
||||||
|
If it is, then that's a bug. (please open a issue)
|
||||||
|
|
||||||
|
## Logged Classes
|
||||||
|
|
||||||
|
If it is hard to add a `LoggedFunction` or `LoggedRoute` to every single method, here is another solution.
|
||||||
|
|
||||||
|
You can use `LoggedInjectable` or `LoggedController` to replace existing `Injectable` or `Controller` decorator from `@nestjs/common`.
|
||||||
|
|
||||||
|
It simply apply `LoggedFunction` or `LoggedRoute` to every single method, and apply `Injectable` or `Controller` decorator to the target class.
|
||||||
|
|
||||||
|
Use like this:
|
||||||
|
|
||||||
|
```ts
|
||||||
|
@LoggedInjectable()
|
||||||
|
class LoggedClass {
|
||||||
|
async testParameterLoggingWithoutInjection(@LoggedParam("key") key: number) {
|
||||||
|
console.log(key);
|
||||||
|
}
|
||||||
|
// ...
|
||||||
|
}
|
||||||
|
|
||||||
|
tester = new LoggedClass();
|
||||||
|
|
||||||
|
tester.testParameterLoggingWithoutInjection(1);
|
||||||
|
```
|
||||||
|
|
||||||
|
It is same as applying `LoggedFunction` to the method.
|
||||||
|
|
||||||
|
But still, if you don't want to apply logging decorator to some methods, you have to apply logging decorator to other methods one by one.
|
||||||
Loading…
x
Reference in New Issue
Block a user