loghandler.go 3.9 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165
  1. package handler
  2. import (
  3. "bytes"
  4. "context"
  5. "fmt"
  6. "io"
  7. "net/http"
  8. "net/http/httputil"
  9. "time"
  10. "zero/core/iox"
  11. "zero/core/logx"
  12. "zero/core/timex"
  13. "zero/core/utils"
  14. "zero/ngin/internal"
  15. )
  16. const slowThreshold = time.Millisecond * 500
  17. type LoggedResponseWriter struct {
  18. w http.ResponseWriter
  19. r *http.Request
  20. code int
  21. }
  22. func (w *LoggedResponseWriter) Header() http.Header {
  23. return w.w.Header()
  24. }
  25. func (w *LoggedResponseWriter) Write(bytes []byte) (int, error) {
  26. return w.w.Write(bytes)
  27. }
  28. func (w *LoggedResponseWriter) WriteHeader(code int) {
  29. w.w.WriteHeader(code)
  30. w.code = code
  31. }
  32. func LogHandler(next http.Handler) http.Handler {
  33. return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
  34. timer := utils.NewElapsedTimer()
  35. logs := new(internal.LogCollector)
  36. lrw := LoggedResponseWriter{
  37. w: w,
  38. r: r,
  39. code: http.StatusOK,
  40. }
  41. var dup io.ReadCloser
  42. r.Body, dup = iox.DupReadCloser(r.Body)
  43. next.ServeHTTP(&lrw, r.WithContext(context.WithValue(r.Context(), internal.LogContext, logs)))
  44. r.Body = dup
  45. logBrief(r, lrw.code, timer, logs)
  46. })
  47. }
  48. type DetailLoggedResponseWriter struct {
  49. writer *LoggedResponseWriter
  50. buf *bytes.Buffer
  51. }
  52. func newDetailLoggedResponseWriter(writer *LoggedResponseWriter, buf *bytes.Buffer) *DetailLoggedResponseWriter {
  53. return &DetailLoggedResponseWriter{
  54. writer: writer,
  55. buf: buf,
  56. }
  57. }
  58. func (w *DetailLoggedResponseWriter) Header() http.Header {
  59. return w.writer.Header()
  60. }
  61. func (w *DetailLoggedResponseWriter) Write(bs []byte) (int, error) {
  62. w.buf.Write(bs)
  63. return w.writer.Write(bs)
  64. }
  65. func (w *DetailLoggedResponseWriter) WriteHeader(code int) {
  66. w.writer.WriteHeader(code)
  67. }
  68. func DetailedLogHandler(next http.Handler) http.Handler {
  69. return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
  70. timer := utils.NewElapsedTimer()
  71. var buf bytes.Buffer
  72. lrw := newDetailLoggedResponseWriter(&LoggedResponseWriter{
  73. w: w,
  74. r: r,
  75. code: http.StatusOK,
  76. }, &buf)
  77. var dup io.ReadCloser
  78. r.Body, dup = iox.DupReadCloser(r.Body)
  79. logs := new(internal.LogCollector)
  80. next.ServeHTTP(lrw, r.WithContext(context.WithValue(r.Context(), internal.LogContext, logs)))
  81. r.Body = dup
  82. logDetails(r, lrw, timer, logs)
  83. })
  84. }
  85. func dumpRequest(r *http.Request) string {
  86. reqContent, err := httputil.DumpRequest(r, true)
  87. if err != nil {
  88. return err.Error()
  89. } else {
  90. return string(reqContent)
  91. }
  92. }
  93. func logBrief(r *http.Request, code int, timer *utils.ElapsedTimer, logs *internal.LogCollector) {
  94. var buf bytes.Buffer
  95. duration := timer.Duration()
  96. buf.WriteString(fmt.Sprintf("%d - %s - %s - %s - %s",
  97. code, r.RequestURI, internal.GetRemoteAddr(r), r.UserAgent(), timex.ReprOfDuration(duration)))
  98. if duration > slowThreshold {
  99. logx.Slowf("[HTTP] %d - %s - %s - %s - slowcall(%s)",
  100. code, r.RequestURI, internal.GetRemoteAddr(r), r.UserAgent(), timex.ReprOfDuration(duration))
  101. }
  102. ok := isOkResponse(code)
  103. if !ok {
  104. buf.WriteString(fmt.Sprintf("\n%s", dumpRequest(r)))
  105. }
  106. body := logs.Flush()
  107. if len(body) > 0 {
  108. buf.WriteString(fmt.Sprintf("\n%s", body))
  109. }
  110. if ok {
  111. logx.Info(buf.String())
  112. } else {
  113. logx.Error(buf.String())
  114. }
  115. }
  116. func logDetails(r *http.Request, response *DetailLoggedResponseWriter, timer *utils.ElapsedTimer,
  117. logs *internal.LogCollector) {
  118. var buf bytes.Buffer
  119. duration := timer.Duration()
  120. buf.WriteString(fmt.Sprintf("%d - %s - %s\n=> %s\n",
  121. response.writer.code, r.RemoteAddr, timex.ReprOfDuration(duration), dumpRequest(r)))
  122. if duration > slowThreshold {
  123. logx.Slowf("[HTTP] %d - %s - slowcall(%s)\n=> %s\n",
  124. response.writer.code, r.RemoteAddr, timex.ReprOfDuration(duration), dumpRequest(r))
  125. }
  126. body := logs.Flush()
  127. if len(body) > 0 {
  128. buf.WriteString(fmt.Sprintf("%s\n", body))
  129. }
  130. respBuf := response.buf.Bytes()
  131. if len(respBuf) > 0 {
  132. buf.WriteString(fmt.Sprintf("<= %s", respBuf))
  133. }
  134. logx.Info(buf.String())
  135. }
  136. func isOkResponse(code int) bool {
  137. // not server error
  138. return code < http.StatusInternalServerError
  139. }