From 4a0cad44bea693ef1f1139832619de8f17ce1b61 Mon Sep 17 00:00:00 2001 From: Sergey Krylov Date: Sat, 28 Mar 2026 09:44:38 +0300 Subject: [PATCH] feat: add logs --- compose.yml | 2 + package.json | 3 + src/app.module.ts | 22 ++++++++ src/modules/auth/auth.service.ts | 32 ++++++++++- src/modules/otp/otp.service.ts | 16 +++++- yarn.lock | 95 +++++++++++++++++++++++++++++++- 6 files changed, 167 insertions(+), 3 deletions(-) diff --git a/compose.yml b/compose.yml index 77b15fb..864f0c0 100644 --- a/compose.yml +++ b/compose.yml @@ -11,6 +11,8 @@ services: - .env.production.local expose: - '9101' + volumes: + - ../logs/auth:/var/log/services/auth networks: - teacinema diff --git a/package.json b/package.json index 0a3365c..3fe588c 100644 --- a/package.json +++ b/package.json @@ -47,6 +47,9 @@ "class-validator": "^0.14.3", "dotenv-expand": "^12.0.3", "ioredis": "^5.9.2", + "nestjs-pino": "^4.6.1", + "pino": "^10.3.1", + "pino-http": "^11.0.0", "prisma": "^7.3.0", "prom-client": "^15.1.3", "reflect-metadata": "^0.2.2", diff --git a/src/app.module.ts b/src/app.module.ts index 75cc7fe..d88eadb 100644 --- a/src/app.module.ts +++ b/src/app.module.ts @@ -1,5 +1,7 @@ import { Module } from '@nestjs/common' import { ConfigModule } from '@nestjs/config' +import { LoggerModule } from 'nestjs-pino' +import pino from 'pino' import { ObservabilityModule } from '@/observability/observability.module' @@ -21,6 +23,23 @@ import { TelegramModule } from './modules/telegram/telegram.module' import { TokenModule } from './modules/token/token.module' import { UsersModule } from './modules/users/users.module' +const transport = pino.transport({ + target: 'pino/file', + options: { + destination: '/var/log/services/auth/auth.log', + mkdir: true + } +}) + +const logger = pino( + { + level: process.env.LOG_LEVEL || 'info', + messageKey: 'msg', + base: { service: 'auth' } + }, + transport +) + @Module({ imports: [ ConfigModule.forRoot({ @@ -32,6 +51,9 @@ import { UsersModule } from './modules/users/users.module' ], load: [dabataseEnv, grpcEnv, redisEnv, passportEnv, telegramEnv, rmqEnv] }), + LoggerModule.forRoot({ + pinoHttp: { logger } + }), PrismaModule, RedisModule, ObservabilityModule, diff --git a/src/modules/auth/auth.service.ts b/src/modules/auth/auth.service.ts index de4f2a5..7124787 100644 --- a/src/modules/auth/auth.service.ts +++ b/src/modules/auth/auth.service.ts @@ -11,6 +11,7 @@ import { VerifyOtpRequest, VerifyOtpResponse } from '@teacinema/contracts/gen/auth' +import { PinoLogger } from 'nestjs-pino' import { MessagingService } from '@/infra/messaging/messaging.service' import { OtpService } from '@/modules/otp/otp.service' @@ -22,17 +23,22 @@ import { UsersClientGrpc } from '../users/users.grpc' @Injectable() export class AuthService { public constructor( + private readonly logger: PinoLogger, private readonly userRepository: UserRepository, private readonly otpService: OtpService, private readonly tokenService: TokenService, private readonly messagingService: MessagingService, private readonly usersClient: UsersClientGrpc, private readonly configService: ConfigService - ) {} + ) { + this.logger.setContext(AuthService.name) + } public async sendOtp(data: SendOtpRequest): Promise { const { identifier, type } = data + this.logger.debug(`OTP request received from ${identifier} of type ${type}`) + let account: Account | null = null const isPhoneType = type === 'phone' const isEmailType = type === 'email' @@ -44,6 +50,9 @@ export class AuthService { } if (!account) { + this.logger.warn( + `Account not found, creating new account for ${identifier} ` + ) account = await this.userRepository.createAccount({ email: isEmailType ? identifier : undefined, phone: isPhoneType ? identifier : undefined @@ -60,12 +69,16 @@ export class AuthService { type: type as 'email' | 'phone' }) + this.logger.info(`OTP successfully send to ${identifier} of type ${type}`) + return { ok: true } } public async verifyOtp(data: VerifyOtpRequest): Promise { const { identifier, code, type } = data + this.logger.debug(`OTP verify for ${identifier} of type ${type}`) + await this.otpService.verify(identifier, code, type as 'email' | 'phone') const isPhoneType = type === 'phone' @@ -76,6 +89,9 @@ export class AuthService { : await this.userRepository.findByEmail(identifier) if (!account) { + this.logger.warn( + `Account not found, create new account for ${identifier}` + ) throw new RpcException({ code: RpcStatus.NOT_FOUND, details: 'Account not found' @@ -94,6 +110,10 @@ export class AuthService { }) } + this.logger.info( + `OTP verified successfully for ${identifier} of type ${type}` + ) + this.usersClient.create({ id: account.id }).subscribe() return this.tokenService.generateTokens(account.id) @@ -101,9 +121,15 @@ export class AuthService { public refresh(data: RefreshRequest): RefreshResponse { const { refreshToken } = data + this.logger.debug(`Refresh token request received`) const result = this.tokenService.verify(refreshToken) if (!result.valid) { + this.logger.error( + // eslint-disable-next-line @typescript-eslint/ban-ts-comment -- ok + // @ts-expect-error + `Invalid refresh token reason: ${result.reason || 'Unknown'}` + ) throw new RpcException({ code: RpcStatus.UNAUTHENTICATED, // @ts-expect-error -- TODO: fixme @@ -111,6 +137,10 @@ export class AuthService { }) } + this.logger.info( + `Refresh token verified successfully for user ${result.userId}` + ) + return this.tokenService.generateTokens(result.userId) } } diff --git a/src/modules/otp/otp.service.ts b/src/modules/otp/otp.service.ts index 2e7cfdb..0b6e9fa 100644 --- a/src/modules/otp/otp.service.ts +++ b/src/modules/otp/otp.service.ts @@ -1,17 +1,27 @@ import { Injectable } from '@nestjs/common' import { RpcException } from '@nestjs/microservices' import { RpcStatus } from '@teacinema/common' +import { PinoLogger } from 'nestjs-pino' import { createHash } from 'node:crypto' import { RedisService } from '@/infra/redis/redis.service' @Injectable() export class OtpService { - public constructor(private readonly redisService: RedisService) {} + public constructor( + private readonly logger: PinoLogger, + private readonly redisService: RedisService + ) { + this.logger.setContext(OtpService.name) + } public async send(indentifier: string, type: 'email' | 'phone') { const { code, hash } = this.generateCode() + this.logger.debug( + `OTP send to ${indentifier} of type ${type}, code ${code}, hash ${hash}` + ) + await this.redisService.set( `otp:${type}:${indentifier}`, hash, @@ -19,6 +29,8 @@ export class OtpService { 60 * 5 ) + this.logger.debug(`OTP stored to Redis: ${indentifier}`) + return { code, hash } } @@ -54,6 +66,8 @@ export class OtpService { const code = Math.floor(100_000 + Math.random() * 900_000) const hash = createHash('sha256').update(String(code)).digest('hex') + this.logger.debug(`Generated OTP code: ${code}`) + return { code, hash } } } diff --git a/yarn.lock b/yarn.lock index fd04084..aa5afc8 100644 --- a/yarn.lock +++ b/yarn.lock @@ -1952,6 +1952,11 @@ dependencies: "@noble/hashes" "^1.1.5" +"@pinojs/redact@^0.4.0": + version "0.4.0" + resolved "https://registry.yarnpkg.com/@pinojs/redact/-/redact-0.4.0.tgz#c3de060dd12640dcc838516aa2a6803cc7b2e9d6" + integrity sha512-k2ENnmBugE/rzQfEcdWHcCY+/FM3VLzH9cYEsbdsoqrvzAKRhUZeRNhAZvB8OitQJ1TBed3yqWtdjzS6wJKBwg== + "@pkgjs/parseargs@^0.11.0": version "0.11.0" resolved "https://registry.yarnpkg.com/@pkgjs/parseargs/-/parseargs-0.11.0.tgz#a77ea742fab25775145434eb1d2328cf5013ac33" @@ -3057,6 +3062,11 @@ asynckit@^0.4.0: resolved "https://registry.yarnpkg.com/asynckit/-/asynckit-0.4.0.tgz#c79ed97f7f34cb8f2ba1bc9790bcc366474b4b79" integrity sha512-Oei9OH4tRh0YqU3GxhX79dM/mwVgvbZJaSNaRk+bshkj0S5cfHcgYakreBjrHwatXKbz+IoIdYLxrKim2MjW0Q== +atomic-sleep@^1.0.0: + version "1.0.0" + resolved "https://registry.yarnpkg.com/atomic-sleep/-/atomic-sleep-1.0.0.tgz#eb85b77a601fc932cfe432c5acd364a9e2c9075b" + integrity sha512-kNOjDqAh7px0XWNI+4QbzoiR/nTkHAWNud2uvnJquD1/x5a7EQZMJT0AczqK0Qn67oY/TTQ1LbUKajZpp3I9tQ== + aws-ssl-profiles@^1.1.1: version "1.1.2" resolved "https://registry.yarnpkg.com/aws-ssl-profiles/-/aws-ssl-profiles-1.1.2.tgz#157dd77e9f19b1d123678e93f120e6f193022641" @@ -5495,6 +5505,11 @@ neo-async@^2.6.2: resolved "https://registry.yarnpkg.com/neo-async/-/neo-async-2.6.2.tgz#b4aafb93e3aeb2d8174ca53cf163ab7d7308305f" integrity sha512-Yd3UES5mWCSqR+qNT93S3UoYUkqAZ9lLg8a7g9rimsWmYGK8cVToA4/sF3RrshdyV3sAGMXVUmpMYOw+dLpOuw== +nestjs-pino@^4.6.1: + version "4.6.1" + resolved "https://registry.yarnpkg.com/nestjs-pino/-/nestjs-pino-4.6.1.tgz#6547c4488566f6d83dcd590863413a37b15f9a47" + integrity sha512-nuARXa0xpdJ1lY2+fgycIQr6H3g0VgqAWNK3xMYjOFcj2DoPETNXj0lV3Y86nRuI7BUfQp5PGiVoZvT4dTWbpQ== + node-abort-controller@^3.0.1: version "3.1.1" resolved "https://registry.yarnpkg.com/node-abort-controller/-/node-abort-controller-3.1.1.tgz#a94377e964a9a37ac3976d848cb5c765833b8548" @@ -5572,6 +5587,11 @@ ohash@^2.0.11: resolved "https://registry.yarnpkg.com/ohash/-/ohash-2.0.11.tgz#60b11e8cff62ca9dee88d13747a5baa145f5900b" integrity sha512-RdR9FQrFwNBNXAr4GixM8YaRZRJ5PUWbKYbE5eOsrwAjJW0q2REGcf79oYPsLyskQCZG1PLN+S/K1V00joZAoQ== +on-exit-leak-free@^2.1.0: + version "2.1.2" + resolved "https://registry.yarnpkg.com/on-exit-leak-free/-/on-exit-leak-free-2.1.2.tgz#fed195c9ebddb7d9e4c3842f93f281ac8dadd3b8" + integrity sha512-0eJJY6hXLGf1udHwfNftBqH+g73EU4B504nZeKpz1sYRKafAghwxEJunB2O7rDZkL4PGfsMVnTXZ2EjibbqcsA== + on-finished@^2.4.1: version "2.4.1" resolved "https://registry.yarnpkg.com/on-finished/-/on-finished-2.4.1.tgz#58c8c44116e54845ad57f14ab10b03533184ac3f" @@ -5812,6 +5832,45 @@ picomatch@^4.0.2, picomatch@^4.0.3: resolved "https://registry.yarnpkg.com/picomatch/-/picomatch-4.0.3.tgz#796c76136d1eead715db1e7bad785dedd695a042" integrity sha512-5gTmgEY/sqK6gFXLIsQNH19lWb4ebPDLA4SdLP7dsWkIXHWlG66oPuVvXSGFPppYZz8ZDZq0dYYrbHfBCVUb1Q== +pino-abstract-transport@^3.0.0: + version "3.0.0" + resolved "https://registry.yarnpkg.com/pino-abstract-transport/-/pino-abstract-transport-3.0.0.tgz#b21e5f33a297e8c4c915c62b3ce5dd4a87a52c23" + integrity sha512-wlfUczU+n7Hy/Ha5j9a/gZNy7We5+cXp8YL+X+PG8S0KXxw7n/JXA3c46Y0zQznIJ83URJiwy7Lh56WLokNuxg== + dependencies: + split2 "^4.0.0" + +pino-http@^11.0.0: + version "11.0.0" + resolved "https://registry.yarnpkg.com/pino-http/-/pino-http-11.0.0.tgz#ebadef4694fc59aadab9be7e5939aea625b4615f" + integrity sha512-wqg5XIAGRRIWtTk8qPGxkbrfiwEWz1lgedVLvhLALudKXvg1/L2lTFgTGPJ4Z2e3qcRmxoFxDuSdMdMGNM6I1g== + dependencies: + get-caller-file "^2.0.5" + pino "^10.0.0" + pino-std-serializers "^7.0.0" + process-warning "^5.0.0" + +pino-std-serializers@^7.0.0: + version "7.1.0" + resolved "https://registry.yarnpkg.com/pino-std-serializers/-/pino-std-serializers-7.1.0.tgz#a7b0cd65225f29e92540e7853bd73b07479893fc" + integrity sha512-BndPH67/JxGExRgiX1dX0w1FvZck5Wa4aal9198SrRhZjH3GxKQUKIBnYJTdj2HDN3UQAS06HlfcSbQj2OHmaw== + +pino@^10.0.0, pino@^10.3.1: + version "10.3.1" + resolved "https://registry.yarnpkg.com/pino/-/pino-10.3.1.tgz#6552c8f8d8481844c9e452e7bf0be90bff1939ce" + integrity sha512-r34yH/GlQpKZbU1BvFFqOjhISRo1MNx1tWYsYvmj6KIRHSPMT2+yHOEb1SG6NMvRoHRF0a07kCOox/9yakl1vg== + dependencies: + "@pinojs/redact" "^0.4.0" + atomic-sleep "^1.0.0" + on-exit-leak-free "^2.1.0" + pino-abstract-transport "^3.0.0" + pino-std-serializers "^7.0.0" + process-warning "^5.0.0" + quick-format-unescaped "^4.0.3" + real-require "^0.2.0" + safe-stable-stringify "^2.3.1" + sonic-boom "^4.0.1" + thread-stream "^4.0.0" + pirates@^4.0.7: version "4.0.7" resolved "https://registry.yarnpkg.com/pirates/-/pirates-4.0.7.tgz#643b4a18c4257c8a65104b73f3049ce9a0a15e22" @@ -5908,6 +5967,11 @@ prisma@^7.3.0: mysql2 "3.15.3" postgres "3.4.7" +process-warning@^5.0.0: + version "5.0.0" + resolved "https://registry.yarnpkg.com/process-warning/-/process-warning-5.0.0.tgz#566e0bf79d1dff30a72d8bbbe9e8ecefe8d378d7" + integrity sha512-a39t9ApHNx2L4+HBnQKqxxHNs1r7KF+Intd8Q/g1bUh6q0WIp9voPXJ/x0j+ZL45KF1pJd9+q2jLIRMfvEshkA== + prom-client@^15.1.3: version "15.1.3" resolved "https://registry.yarnpkg.com/prom-client/-/prom-client-15.1.3.tgz#69fa8de93a88bc9783173db5f758dc1c69fa8fc2" @@ -5988,6 +6052,11 @@ querystringify@^2.1.1: resolved "https://registry.yarnpkg.com/querystringify/-/querystringify-2.2.0.tgz#3345941b4153cb9d082d8eee4cda2016a9aef7f6" integrity sha512-FIqgj2EUvTa7R50u0rGsyTftzjYmv/a3hO345bZNrqabNqjtgiDMgmo4mkUjd+nzU5oF3dClKqFIPUKybUyqoQ== +quick-format-unescaped@^4.0.3: + version "4.0.4" + resolved "https://registry.yarnpkg.com/quick-format-unescaped/-/quick-format-unescaped-4.0.4.tgz#93ef6dd8d3453cbc7970dd614fad4c5954d6b5a7" + integrity sha512-tYC1Q1hgyRuHgloV/YXs2w15unPVh8qfu/qCTfhTYamaw7fyhumKa2yGpdSo87vY32rIclj+4fWYQXUMs9EHvg== + randombytes@^2.1.0: version "2.1.0" resolved "https://registry.yarnpkg.com/randombytes/-/randombytes-2.1.0.tgz#df6f84372f0270dc65cdf6291349ab7a473d4f2a" @@ -6037,6 +6106,11 @@ readdirp@^4.0.1: resolved "https://registry.yarnpkg.com/readdirp/-/readdirp-4.1.2.tgz#eb85801435fbf2a7ee58f19e0921b068fc69948d" integrity sha512-GDhwkLfywWL2s6vEjyhri+eXmfH6j1L7JE27WhqLeYzoh/A3DBaYGEj2H/HFZCn/kMfim73FXxEJTw06WtxQwg== +real-require@^0.2.0: + version "0.2.0" + resolved "https://registry.yarnpkg.com/real-require/-/real-require-0.2.0.tgz#209632dea1810be2ae063a6ac084fee7e33fba78" + integrity sha512-57frrGM/OCTLqLOAh0mhVA9VBMHd+9U7Zb2THMGdBUoZVOtGbJzjxsYGDJ3A9AYYCP4hn6y1TVbaOfzWtm5GFg== + redis-errors@^1.0.0, redis-errors@^1.2.0: version "1.2.0" resolved "https://registry.yarnpkg.com/redis-errors/-/redis-errors-1.2.0.tgz#eb62d2adb15e4eaf4610c04afe1529384250abad" @@ -6147,6 +6221,11 @@ safe-buffer@^5.1.0, safe-buffer@~5.2.0: resolved "https://registry.yarnpkg.com/safe-buffer/-/safe-buffer-5.2.1.tgz#1eaf9fa9bdb1fdd4ec75f58f9cdb4e6b7827eec6" integrity sha512-rp3So07KcdmmKbGvgaNxQSJr7bGVSVk5S9Eq1F+ppbRo70+YeaDxkw5Dd8NPN+GD6bjnYm2VuPuCXmpuYvmCXQ== +safe-stable-stringify@^2.3.1: + version "2.5.0" + resolved "https://registry.yarnpkg.com/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz#4ca2f8e385f2831c432a719b108a3bf7af42a1dd" + integrity sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA== + "safer-buffer@>= 2.1.2 < 3.0.0": version "2.1.2" resolved "https://registry.yarnpkg.com/safer-buffer/-/safer-buffer-2.1.2.tgz#44fa161b0187b9549dd84bb91802f9bd8385cd6a" @@ -6292,6 +6371,13 @@ slash@^3.0.0: resolved "https://registry.yarnpkg.com/slash/-/slash-3.0.0.tgz#6539be870c165adbd5240220dbe361f1bc4d4634" integrity sha512-g9Q1haeby36OSStwb4ntCGGGaKsaVSjQ68fBxoQcutl5fS1vuY18H3wSt3jFyFtrkx+Kz0V1G85A4MyAdDMi2Q== +sonic-boom@^4.0.1: + version "4.2.1" + resolved "https://registry.yarnpkg.com/sonic-boom/-/sonic-boom-4.2.1.tgz#28598250df4899c0ac572d7e2f0460690ba6a030" + integrity sha512-w6AxtubXa2wTXAUsZMMWERrsIRAdrK0Sc+FUytWvYAhBJLyuI4llrMIC1DtlNSdI99EI86KZum2MMq3EAZlF9Q== + dependencies: + atomic-sleep "^1.0.0" + source-map-support@0.5.13: version "0.5.13" resolved "https://registry.yarnpkg.com/source-map-support/-/source-map-support-0.5.13.tgz#31b24a9c2e73c2de85066c0feb7d44767ed52932" @@ -6323,7 +6409,7 @@ source-map@^0.7.4: resolved "https://registry.yarnpkg.com/source-map/-/source-map-0.7.6.tgz#a3658ab87e5b6429c8a1f3ba0083d4c61ca3ef02" integrity sha512-i5uvt8C3ikiWeNZSVZNWcfZPItFQOsYTUAOkcUPGd8DqDy1uOUikjt5dG+uRlwyvR108Fb9DOd4GvXfT0N2/uQ== -split2@^4.1.0: +split2@^4.0.0, split2@^4.1.0: version "4.2.0" resolved "https://registry.yarnpkg.com/split2/-/split2-4.2.0.tgz#c9c5920904d148bab0b9f67145f245a86aadbfa4" integrity sha512-UcjcJOWknrNkF6PLX83qcHM6KHgVKNkV62Y8a5uYDVv9ydGQVwAHMKqHdJje1VTWpljG0WYpCDhrCdAOYH4TWg== @@ -6547,6 +6633,13 @@ test-exclude@^6.0.0: glob "^7.1.4" minimatch "^3.0.4" +thread-stream@^4.0.0: + version "4.0.0" + resolved "https://registry.yarnpkg.com/thread-stream/-/thread-stream-4.0.0.tgz#732f007c24da7084f729d6e3a7e3f5934a7380b7" + integrity sha512-4iMVL6HAINXWf1ZKZjIPcz5wYaOdPhtO8ATvZ+Xqp3BTdaqtAwQkNmKORqcIo5YkQqGXq5cwfswDwMqqQNrpJA== + dependencies: + real-require "^0.2.0" + tinyexec@^1.0.2: version "1.0.2" resolved "https://registry.yarnpkg.com/tinyexec/-/tinyexec-1.0.2.tgz#bdd2737fe2ba40bd6f918ae26642f264b99ca251"