-1

为什么 Golog包会减慢我的 http API 的速度？有那么慢吗？

这是我使用httprouter 而不记录的路由器示例：

package main

import (
    "fmt"
    "log"
    "net/http"
    "time"

    "github.com/julienschmidt/httprouter"
)

func main() {
    handler := httprouter.New()
    handler.GET("/hello", f)
    http.ListenAndServe(fmt.Sprintf(":%d", 8080), handler)
}

func f(w http.ResponseWriter, r *http.Request, ps httprouter.Params) {
    w.WriteHeader(http.StatusOK)
    fmt.Fprint(w, "world")
}

使用wrk对该端点进行基准测试，我得到了这个：

$ wrk -t1 -d1s -c100 http://localhost:8080/hello
Running 1s test @ http://localhost:8080/hello
  1 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     1.15ms  197.55us   2.84ms   80.02%
    Req/Sec    84.58k     6.15k   99.01k    80.00%
  83904 requests in 1.01s, 9.68MB read
Requests/sec:  83380.37
Transfer/sec:      9.62MB

当我添加中间件进行日志记录时：

package main

import (
    "fmt"
    "log"
    "net/http"
    "time"

    "github.com/julienschmidt/httprouter"
)

func main() {
    handler := httprouter.New()
    handler.GET("/hello", logger(f))
    fmt.Println("httprouter")
    http.ListenAndServe(fmt.Sprintf(":%d", 8080), handler)
}

func logger(next httprouter.Handle) httprouter.Handle {
    return func(w http.ResponseWriter, r *http.Request, ps httprouter.Params) {
        start := time.Now()
        next(w, r, ps)
        elapsed := time.Since(start)
        log.Printf("%s | %s | %s | %d\n", time.Now().Format(time.RFC3339), r.Method, r.URL.Path, elapsed)
    }
}

func f(w http.ResponseWriter, r *http.Request, ps httprouter.Params) {
    w.WriteHeader(http.StatusOK)
    fmt.Fprint(w, "world")
}

它被减慢到 4 倍：

$ wrk -t1 -d1s -c100 http://localhost:8080/hello
Running 1s test @ http://localhost:8080/hello
  1 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     5.25ms    4.34ms  26.47ms   60.23%
    Req/Sec    20.51k     2.19k   24.28k    70.00%
  20449 requests in 1.01s, 2.36MB read
Requests/sec:  20330.66
Transfer/sec:      2.35MB

我在本地对其进行了测试：

MacBook Pro 13inches
2 GHz Quad-Core Intel Core i5
Memory 16GB

I use default Go max proc without modifying anything after installed.

log包这么慢？有什么建议可以改善吗？

4

1 回答 1

1

该答案总结了对该问题的评论。

  • 使用缓冲 io
  • 从 goroutine 写入以减少来自其他日志记录 goroutine 的阻塞。

这是代码：

type writer chan []byte

func (w writer) Write(p []byte) (int, error) {
    w <- append(([]byte)(nil), p...)
    return len(p), nil
}

func writePump(w writer) {
    bw := bufio.NewWriter(os.Stderr)
    for p := range w {
        bw.Write(p)

        // Slurp up buffered messages in flush. This ensures
        // timely output.
        n := len(w)
        for i := 0; i < n; i++ {
            bw.Write(<-w)
        }
        bw.Flush()
    }
}

设置如下：

w := make(writer, 16) // adjust capacity to meet your needs
go writePump(w)
log.SetOutput(w)
于 2020-11-19T06:17:10.620 回答