Let's Go Further معیارها › معیارهای سطح درخواست
قبلی · فهرست مطالب · بعدی
فصل ۱۸.۳.

معیارهای سطح درخواست

در این فصل قصد داریم middleware جدیدی ایجاد کنیم تا request-level سفارشی برای برنامه خود ثبت کنیم. ابتدا سه مورد زیر را ثبت خواهیم کرد:

تمام این مقادیر عدد صحیح (integer) خواهند بود، بنابراین می‌توانیم این معیارها را با استفاده از تابع expvar.NewInt() در پکیج expvar ثبت کنیم.

بیایید مستقیماً وارد کد شویم و یک متد middleware جدید metrics() ایجاد کنیم که متغیرهای expvar لازم را مقداردهی اولیه کند و سپس هر بار که درخواستی را پردازش می‌کنیم آنها را به‌روز کند. به این صورت:

فایل: cmd/api/middleware.go
package main

import (
    "errors"
    "expvar" // New import
    "fmt"
    "net"
    "net/http"
    "strings"
    "sync"
    "time"

    "greenlight.alexedwards.net/internal/data"
    "greenlight.alexedwards.net/internal/validator"

    "golang.org/x/time/rate"
)

...

func (app *application) metrics(next http.Handler) http.Handler {
    // Initialize the new expvar variables when the middleware chain is first built.
    var (
        totalRequestsReceived           = expvar.NewInt("total_requests_received")
        totalResponsesSent              = expvar.NewInt("total_responses_sent")
        totalProcessingTimeMicroseconds = expvar.NewInt("total_processing_time_μs")
    )

    // The following code will be run for every request...
    return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
        // Record the time that we started to process the request.
        start := time.Now()

        // Use the Add() method to increment the number of requests received by 1.
        totalRequestsReceived.Add(1)

        // Call the next handler in the chain.
        next.ServeHTTP(w, r)

        // On the way back up the middleware chain, increment the number of responses
        // sent by 1.
        totalResponsesSent.Add(1)

        // Calculate the number of microseconds since we began to process the request,
        // then increment the total processing time by this amount.
        duration := time.Since(start).Microseconds()
        totalProcessingTimeMicroseconds.Add(duration)
    })
}

پس از اتمام این کار، باید فایل cmd/api/routes.go را به‌روز کنیم تا middleware جدید metrics() را در ابتدای زنجیره قرار دهیم. به این صورت:

فایل: cmd/api/routes.go
package main

...

func (app *application) routes() http.Handler {
    router := httprouter.New()

    router.NotFound = http.HandlerFunc(app.notFoundResponse)
    router.MethodNotAllowed = http.HandlerFunc(app.methodNotAllowedResponse)

    router.HandlerFunc(http.MethodGet, "/v1/healthcheck", app.healthcheckHandler)

    router.HandlerFunc(http.MethodGet, "/v1/movies", app.requirePermission("movies:read", app.listMoviesHandler))
    router.HandlerFunc(http.MethodPost, "/v1/movies", app.requirePermission("movies:write", app.createMovieHandler))
    router.HandlerFunc(http.MethodGet, "/v1/movies/:id", app.requirePermission("movies:read", app.showMovieHandler))
    router.HandlerFunc(http.MethodPatch, "/v1/movies/:id", app.requirePermission("movies:write", app.updateMovieHandler))
    router.HandlerFunc(http.MethodDelete, "/v1/movies/:id", app.requirePermission("movies:write", app.deleteMovieHandler))

    router.HandlerFunc(http.MethodPost, "/v1/users", app.registerUserHandler)
    router.HandlerFunc(http.MethodPut, "/v1/users/activated", app.activateUserHandler)

    router.HandlerFunc(http.MethodPost, "/v1/tokens/authentication", app.createAuthenticationTokenHandler)

    router.Handler(http.MethodGet, "/debug/vars", expvar.Handler())

    // Use the new metrics() middleware at the start of the chain.
    return app.metrics(app.recoverPanic(app.enableCORS(app.rateLimit(app.authenticate(router)))))
}

خوب، بیایید آن را امتحان کنیم. API را با غیرفعال کردن rate limiting اجرا کنید:

$ go run ./cmd/api -limiter-enabled=false
time=2023-09-10T10:59:13.722+02:00 level=INFO msg="database connection pool established"
time=2023-09-10T10:59:13.722+02:00 level=INFO msg="starting server" addr=:4000 env=development

و وقتی در مرورگر خود به localhost:4000/debug/vars مراجعه می‌کنید، باید ببینید که پاسخ JSON شامل موارد total_requests_received، total_responses_sent و total_processing_time_μs است. به این صورت:

18.03-01.png

در این نقطه، می‌توانیم ببینیم که API ما یک درخواست دریافت کرده و صفر پاسخ ارسال کرده است. اگر فکر کنید، این منطقی است — در لحظه‌ای که این پاسخ JSON تولید شد، هنوز واقعاً ارسال نشده بود.

اگر صفحه را رفرش کنید، باید ببینید که این اعداد افزایش می‌یابند — از جمله افزایش مقدار total_processing_time_μs:

18.03-02.png

بیایید آن را تحت بار آزمایش کنیم و دوباره از hey برای ارسال درخواست‌ها به endpoint POST /v1/tokens/authentication استفاده کنیم.

ابتدا API را مجدداً راه‌اندازی کنید:

$ go run ./cmd/api -limiter-enabled=false
time=2023-09-10T10:59:13.722+02:00 level=INFO msg="database connection pool established"
time=2023-09-10T10:59:13.722+02:00 level=INFO msg="starting server" addr=:4000 env=development

و سپس با hey بار را به این صورت تولید کنید:

$ BODY='{"email": "alice@example.com", "password": "pa55word"}'
$ hey -d "$BODY" -m "POST" http://localhost:4000/v1/tokens/authentication

Summary:
  Total:        9.9141 secs
  Slowest:      3.0333 secs
  Fastest:      1.6788 secs
  Average:      2.4302 secs
  Requests/sec: 20.1732
  
  Total data:   24987 bytes
  Size/request: 124 bytes

Response time histogram:
  1.679 [1]  |■
  1.814 [1]  |■
  1.950 [3]  |■■■
  2.085 [8]  |■■■■■■■
  2.221 [28] |■■■■■■■■■■■■■■■■■■■■■■■■
  2.356 [39] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  2.491 [46] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  2.627 [34] |■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  2.762 [20] |■■■■■■■■■■■■■■■■■
  2.898 [9]  |■■■■■■■■
  3.033 [11] |■■■■■■■■■■


Latency distribution:
  10% in 2.1386 secs
  25% in 2.2678 secs
  50% in 2.4197 secs
  75% in 2.5769 secs
  90% in 2.7718 secs
  95% in 2.9125 secs
  99% in 3.0220 secs

Details (average, fastest, slowest):
  DNS+dialup: 0.0007 secs, 1.6788 secs, 3.0333 secs
  DNS-lookup: 0.0005 secs, 0.0000 secs, 0.0047 secs
  req write:  0.0001 secs, 0.0000 secs, 0.0012 secs
  resp wait:  2.4293 secs, 1.6787 secs, 3.0293 secs
  resp read:  0.0000 secs, 0.0000 secs, 0.0001 secs

Status code distribution:
  [201]	200 responses

پس از اتمام کار، اگر localhost:4000/debug/vars را در مرورگر خود رفرش کنید، معیارهای شما باید چیزی شبیه به این باشند:

18.03-03.png

بر اساس مقادیر total_processing_time_μs و total_responses_sent، می‌توانیم محاسبه کنیم که زمان پردازش متوسط به ازای هر درخواست تقریباً ۲.۴ ثانیه بوده است (به یاد داشته باشید که این endpoint عمداً کند و پرهزینه از نظر محاسباتی است زیرا باید رمز عبور کاربر bcrypted را تأیید کنیم).

481455830 μs / 201 reqs =  2395303 μs/req = 2.4 s/req

این با داده‌هایی که در خلاصه نتایج hey می‌بینیم همخوانی دارد که زمان پاسخ متوسط را ۲.۴۳۰۲ ثانیه نشان می‌دهد. مقدار hey زمان کل round-trip است، بنابراین همیشه کمی بالاتر خواهد بود زیرا شامل network latency و زمان صرف شده برای مدیریت درخواست توسط http.Server می‌شود.


اطلاعات تکمیلی

محاسبه معیارهای اضافی

بر اساس اطلاعات موجود در پاسخ GET /debug/vars، می‌توانید برخی معیارهای اضافی جالب نیز استخراج کنید. مانند…