Let's Go بهبودهای سرور و امنیت › لاگ خطای سرور
قبلی · فهرست · بعدی
فصل ۹.۲.

لاگ خطای سرور

مهم است که بدانیم http.Server در Go ممکن است ورودی‌های لاگ خود را در مورد چیزهایی مانند panicهای بازیابی نشده، یا مشکلات پذیرش یا نوشتن در اتصال‌های HTTP بنویسد.

به طور پیش‌فرض، این ورودی‌ها را با استفاده از لاگر استاندارد می‌نویسد — که به این معنی است که آن‌ها به جریان خطای استاندارد نوشته می‌شوند (به جای خروجی استاندارد مانند سایر ورودی‌های لاگ ما)، و آن‌ها در همان فرمت سایر ورودی‌های لاگ ساختاریافته ما نخواهند بود.

برای نشان دادن این، بیایید یک خطای عمدی به برنامه خود اضافه کنیم و یک هدر Content-Length با مقدار نامعتبر در پاسخ‌های خود تنظیم کنیم. بروید و helper render() را به این صورت به‌روزرسانی کنید:

File: cmd/web/helpers.go
package main

...

func (app *application) render(w http.ResponseWriter, r *http.Request, status int, page string, data templateData) {
    ts, ok := app.templateCache[page]
    if !ok {
        err := fmt.Errorf("the template %s does not exist", page)
        app.serverError(w, r, err)
        return
    }

    buf := new(bytes.Buffer)

    err := ts.ExecuteTemplate(buf, "base", data)
    if err != nil {
        app.serverError(w, r, err)
        return
    }
    
    // Deliberate error: set a Content-Length header with an invalid (non-integer) 
    // value.
    w.Header().Set("Content-Length", "this isn't an integer!")

    w.WriteHeader(status)

    buf.WriteTo(w)
}

...

سپس برنامه را اجرا کنید، یک درخواست به http://localhost:4000 ارسال کنید و لاگ برنامه را بررسی کنید. باید ببینید که چیزی شبیه به این است:

$ go run ./cmd/web/
time=2024-03-18T11:29:23.000+00:00 level=INFO msg="starting server" addr=:4000
time=2024-03-18T11:29:23.000+00:00 level=INFO msg="received request" ip=127.0.0.1:60824 proto=HTTP/1.1 method=GET uri=/
2024/03/18 11:29:23 http: invalid Content-Length of "this isn't an integer!"
time=2024-03-18T11:29:23.000+00:00 level=INFO msg="received request" ip=127.0.0.1:60824 proto=HTTP/1.1 method=GET uri=/static/css/main.css
time=2024-03-18T11:29:23.000+00:00 level=INFO msg="received request" ip=127.0.0.1:60830 proto=HTTP/1.1 method=GET uri=/static/img/logo.png

می‌توانیم ببینیم که سومین ورودی لاگ در اینجا، که ما را از مشکل Content-Length مطلع می‌کند، در فرمتی بسیار متفاوت از سایرین است. این خوب نیست، به خصوص اگر می‌خواهید لاگ‌های خود را برای جستجوی خطاها فیلتر کنید، یا از یک سرویس خارجی برای نظارت بر آن‌ها و ارسال هشدار استفاده کنید.

متأسفانه، امکان پیکربندی http.Server برای استفاده مستقیم از لاگر ساختاریافته جدید ما وجود ندارد. در عوض، باید handler لاگر ساختاریافته خود را به یک *log.Logger تبدیل کنیم که ورودی‌های لاگ را در یک سطح ثابت خاص می‌نویسد، و سپس آن را با http.Server ثبت کنیم. می‌توانیم این تبدیل را با استفاده از تابع slog.NewLogLogger() انجام دهیم، به این صورت:

File: cmd/web/main.go
package main

...

func main() {
    addr := flag.String("addr", ":4000", "HTTP network address")
    dsn := flag.String("dsn", "web:pass@/snippetbox?parseTime=true", "MySQL data source name")
    flag.Parse()

    logger := slog.New(slog.NewTextHandler(os.Stdout, nil))

    ...

    srv := &http.Server{
        Addr:     *addr,
        Handler:  app.routes(),
        // Create a *log.Logger from our structured logger handler, which writes
        // log entries at Error level, and assign it to the ErrorLog field. If 
        // you would prefer to log the server errors at Warn level instead, you
        // could pass slog.LevelWarn as the final parameter.
        ErrorLog: slog.NewLogLogger(logger.Handler(), slog.LevelError),
    }

    logger.Info("starting server", "addr", srv.Addr)

    err = srv.ListenAndServe()
    logger.Error(err.Error())
    os.Exit(1)
}

...

با این کار، هر پیام لاگی که http.Server به طور خودکار می‌نویسد اکنون با استفاده از لاگر ساختاریافته ما در سطح Error نوشته خواهد شد. اگر برنامه را مجدداً راه‌اندازی کنید و یک درخواست دیگر به http://localhost:4000 ارسال کنید، باید ببینید که ورودی‌های لاگ اکنون به این صورت هستند:

$ go run ./cmd/web/
time=2024-03-18T11:29:23.000+00:00 level=INFO msg="starting server" addr=:4000
time=2024-03-18T11:29:23.000+00:00 level=INFO msg="received request" ip=127.0.0.1:40854 proto=HTTP/1.1 method=GET uri=/
time=2024-03-18T11:29:23.000+00:00 level=ERROR msg="http: invalid Content-Length of \"this isn't an integer!\""

قبل از اینکه بیشتر پیش برویم، به فایل cmd/web/helpers.go خود برگردید و خطای عمدی را از متد render() حذف کنید:

File: cmd/web/helpers.go
package main

...

func (app *application) render(w http.ResponseWriter, r *http.Request, status int, page string, data templateData) {
    ts, ok := app.templateCache[page]
    if !ok {
        err := fmt.Errorf("the template %s does not exist", page)
        app.serverError(w, r, err)
        return
    }

    buf := new(bytes.Buffer)

    err := ts.ExecuteTemplate(buf, "base", data)
    if err != nil {
        app.serverError(w, r, err)
        return
    }
    
    w.WriteHeader(status)

    buf.WriteTo(w)
}

...