Repository: cloudwego/hertz
Pull request #550 (2023-01-17 06:46:04)

chore(hz): release hz v0.5.1

codecov[bot]: # [Codecov](https://codecov.io/gh/cloudwego/hertz/pull/550?src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=cloudwego) Report
Base: **69.87**% // Head: **69.87**% // No change to project coverage :thumbsup:
> Coverage data is based on head [(`0aedd9b`)](https://codecov.io/gh/cloudwego/hertz/pull/550?src=pr&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=cloudwego) compared to base [(`327716b`)](https://codecov.io/gh/cloudwego/hertz/commit/327716b661b8bf59bd9a668bec9559b71fe1291d?el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=cloudwego).
> Patch has no changes to coverable lines.

<details><summary>Additional details and impacted files</summary>


```diff
@@           Coverage Diff            @@
##           develop     #550   +/-   ##
========================================
  Coverage    69.87%   69.87%           
========================================
  Files           93       93           
  Lines         8887     8887           
========================================
  Hits          6210     6210           
  Misses        2307     2307           
  Partials       370      370           
```



Help us with your feedback. Take ten seconds to tell us [how you rate us](https://about.codecov.io/nps?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=cloudwego). Have a feature suggestion? [Share it here.](https://app.codecov.io/gh/feedback/?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=cloudwego)

</details>

[:umbrella: View full report at Codecov](https://codecov.io/gh/cloudwego/hertz/pull/550?src=pr&el=continue&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=cloudwego).   
:loudspeaker: Do you have feedback about the report comment? [Let us know in this issue](https://about.codecov.io/codecov-pr-comment-feedback/?utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=cloudwego).


Patch:
diff --git a/cmd/hz/meta/const.go b/cmd/hz/meta/const.go
index 0bcb21f..00c0aa8 100644
--- a/cmd/hz/meta/const.go
+++ b/cmd/hz/meta/const.go
@@ -19,7 +19,7 @@ package meta
 import "runtime"
 
 // Version hz version
-const Version = "v0.5.0"
+const Version = "v0.5.1"
 
 // Mode hz run modes
 type Mode int
diff --git a/pkg/protocol/http1/factory/server.go b/pkg/protocol/http1/factory/server.go
index 99029eb..513303b 100644
--- a/pkg/protocol/http1/factory/server.go
+++ b/pkg/protocol/http1/factory/server.go
@@ -30,10 +30,10 @@ type serverFactory struct {
 
 // New is called by Hertz during engine.Run()
 func (s *serverFactory) New(core suite.Core) (server protocol.Server, err error) {
-	return &http1.Server{
-		Option: *s.option,
-		Core:   core,
-	}, nil
+	serv := http1.NewServer()
+	serv.Option = *s.option
+	serv.Core = core
+	return serv, nil
 }
 
 func NewServerFactory(option *http1.Option) suite.ServerFactory {
diff --git a/pkg/protocol/http1/server.go b/pkg/protocol/http1/server.go
index 6ff8d7d..99d2da7 100644
--- a/pkg/protocol/http1/server.go
+++ b/pkg/protocol/http1/server.go
@@ -22,6 +22,7 @@ import (
 	"errors"
 	"io"
 	"net"
+	"sync"
 	"time"
 
 	"github.com/cloudwego/hertz/internal/bytestr"
@@ -30,6 +31,7 @@ import (
 	"github.com/cloudwego/hertz/pkg/app/server/render"
 	errs "github.com/cloudwego/hertz/pkg/common/errors"
 	"github.com/cloudwego/hertz/pkg/common/tracer/stats"
+	"github.com/cloudwego/hertz/pkg/common/tracer/traceinfo"
 	"github.com/cloudwego/hertz/pkg/network"
 	"github.com/cloudwego/hertz/pkg/protocol"
 	"github.com/cloudwego/hertz/pkg/protocol/consts"
@@ -71,6 +73,8 @@ type Option struct {
 type Server struct {
 	Option
 	Core suite.Core
+
+	eventStackPool *sync.Pool
 }
 
 func (s Server) Serve(c context.Context, conn network.Conn) (err error) {
@@ -93,19 +97,31 @@ func (s Server) Serve(c context.Context, conn network.Conn) (err error) {
 		// 4. Reset and recycle
 		ctx = s.Core.GetCtxPool().Get().(*app.RequestContext)
 
-		traceCtl = s.Core.GetTracer()
+		traceCtl        = s.Core.GetTracer()
+		eventsToTrigger *eventStack
 
 		// Use a new variable to hold the standard context to avoid modify the initial
 		// context.
 		cc = c
 	)
 
+	if s.EnableTrace {
+		eventsToTrigger = s.eventStackPool.Get().(*eventStack)
+	}
+
 	defer func() {
-		// error case
-		if err != nil && s.EnableTrace {
-			if !errors.Is(err, errs.ErrIdleTimeout) && !errors.Is(err, errs.ErrHijacked) {
+		if s.EnableTrace {
+			if err != nil && !errors.Is(err, errs.ErrIdleTimeout) && !errors.Is(err, errs.ErrHijacked) {
 				ctx.GetTraceInfo().Stats().SetError(err)
 			}
+			// in case of error, we need to trigger all events
+			if eventsToTrigger != nil {
+				for last := eventsToTrigger.pop(); last != nil; last = eventsToTrigger.pop() {
+					last(ctx.GetTraceInfo(), err)
+				}
+				s.eventStackPool.Put(eventsToTrigger)
+			}
+
 			traceCtl.DoFinish(cc, ctx, err)
 		}
 
@@ -142,7 +158,7 @@ func (s Server) Serve(c context.Context, conn network.Conn) (err error) {
 			ctx.GetConn().SetReadTimeout(s.IdleTimeout) //nolint:errcheck
 
 			_, err = zr.Peek(4)
-			// This is not the first request and we haven't read a single byte
+			// This is not the first request, and we haven't read a single byte
 			// of a new request yet. This means it's just a keep-alive connection
 			// closing down either because the remote closed it or because
 			// or a read timeout on our side. Either way just close the connection
@@ -159,12 +175,21 @@ func (s Server) Serve(c context.Context, conn network.Conn) (err error) {
 		if s.EnableTrace {
 			cc = traceCtl.DoStart(c, ctx)
 			internalStats.Record(ctx.GetTraceInfo(), stats.ReadHeaderStart, err)
+			eventsToTrigger.push(func(ti traceinfo.TraceInfo, err error) {
+				internalStats.Record(ti, stats.ReadHeaderFinish, err)
+			})
 		}
 		// Read Headers
 		if err = req.ReadHeader(&ctx.Request.Header, zr); err == nil {
 			if s.EnableTrace {
-				internalStats.Record(ctx.GetTraceInfo(), stats.ReadHeaderFinish, err)
+				// read header finished
+				if last := eventsToTrigger.pop(); last != nil {
+					last(ctx.GetTraceInfo(), err)
+				}
 				internalStats.Record(ctx.GetTraceInfo(), stats.ReadBodyStart, err)
+				eventsToTrigger.push(func(ti traceinfo.TraceInfo, err error) {
+					internalStats.Record(ti, stats.ReadBodyFinish, err)
+				})
 			}
 			// Read body
 			if s.StreamRequestBody {
@@ -180,7 +205,10 @@ func (s Server) Serve(c context.Context, conn network.Conn) (err error) {
 			} else {
 				ctx.GetTraceInfo().Stats().SetRecvSize(0)
 			}
-			internalStats.Record(ctx.GetTraceInfo(), stats.ReadBodyFinish, err)
+			// read body finished
+			if last := eventsToTrigger.pop(); last != nil {
+				last(ctx.GetTraceInfo(), err)
+			}
 		}
 
 		if err != nil {
@@ -241,6 +269,9 @@ func (s Server) Serve(c context.Context, conn network.Conn) (err error) {
 		}
 		if s.EnableTrace {
 			internalStats.Record(ctx.GetTraceInfo(), stats.ServerHandleStart, err)
+			eventsToTrigger.push(func(ti traceinfo.TraceInfo, err error) {
+				internalStats.Record(ti, stats.ServerHandleFinish, err)
+			})
 		}
 		// Handle the request
 		//
@@ -248,7 +279,10 @@ func (s Server) Serve(c context.Context, conn network.Conn) (err error) {
 		// and the route has been matched.
 		s.Core.ServeHTTP(cc, ctx)
 		if s.EnableTrace {
-			internalStats.Record(ctx.GetTraceInfo(), stats.ServerHandleFinish, err)
+			// application layer handle finished
+			if last := eventsToTrigger.pop(); last != nil {
+				last(ctx.GetTraceInfo(), err)
+			}
 		}
 
 		// exit check
@@ -275,6 +309,9 @@ func (s Server) Serve(c context.Context, conn network.Conn) (err error) {
 		}
 		if s.EnableTrace {
 			internalStats.Record(ctx.GetTraceInfo(), stats.WriteStart, err)
+			eventsToTrigger.push(func(ti traceinfo.TraceInfo, err error) {
+				internalStats.Record(ti, stats.WriteFinish, err)
+			})
 		}
 		if err = writeResponse(ctx, zw); err != nil {
 			return
@@ -298,7 +335,10 @@ func (s Server) Serve(c context.Context, conn network.Conn) (err error) {
 			return
 		}
 		if s.EnableTrace {
-			internalStats.Record(ctx.GetTraceInfo(), stats.WriteFinish, err)
+			// write finished
+			if last := eventsToTrigger.pop(); last != nil {
+				last(ctx.GetTraceInfo(), err)
+			}
 		}
 
 		// Release request body stream
@@ -345,6 +385,16 @@ func (s Server) Serve(c context.Context, conn network.Conn) (err error) {
 	}
 }
 
+func NewServer() *Server {
+	return &Server{
+		eventStackPool: &sync.Pool{
+			New: func() interface{} {
+				return &eventStack{}
+			},
+		},
+	}
+}
+
 func writeErrorResponse(zw network.Writer, ctx *app.RequestContext, serverName []byte, err error) network.Writer {
 	errorHandler := defaultErrorHandler
 
@@ -380,3 +430,22 @@ func defaultErrorHandler(ctx *app.RequestContext, err error) {
 		ctx.AbortWithMsg("Error when parsing request", consts.StatusBadRequest)
 	}
 }
+
+type eventStack []func(ti traceinfo.TraceInfo, err error)
+
+func (e *eventStack) isEmpty() bool {
+	return len(*e) == 0
+}
+
+func (e *eventStack) push(f func(ti traceinfo.TraceInfo, err error)) {
+	*e = append(*e, f)
+}
+
+func (e *eventStack) pop() func(ti traceinfo.TraceInfo, err error) {
+	if e.isEmpty() {
+		return nil
+	}
+	last := (*e)[len(*e)-1]
+	*e = (*e)[:len(*e)-1]
+	return last
+}


Test patch:
diff --git a/pkg/protocol/http1/server_test.go b/pkg/protocol/http1/server_test.go
new file mode 100644
index 0000000..4a2a15a
--- /dev/null
+++ b/pkg/protocol/http1/server_test.go
@@ -0,0 +1,223 @@
+/*
+ * Copyright 2023 CloudWeGo Authors
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package http1
+
+import (
+	"context"
+	"errors"
+	"sync"
+	"testing"
+
+	inStats "github.com/cloudwego/hertz/internal/stats"
+	"github.com/cloudwego/hertz/pkg/app"
+	errs "github.com/cloudwego/hertz/pkg/common/errors"
+	"github.com/cloudwego/hertz/pkg/common/test/assert"
+	"github.com/cloudwego/hertz/pkg/common/test/mock"
+	"github.com/cloudwego/hertz/pkg/common/tracer"
+	"github.com/cloudwego/hertz/pkg/common/tracer/stats"
+	"github.com/cloudwego/hertz/pkg/common/tracer/traceinfo"
+	"github.com/cloudwego/hertz/pkg/network"
+)
+
+var pool = &sync.Pool{New: func() interface{} {
+	return &eventStack{}
+}}
+
+func TestTraceEventCompleted(t *testing.T) {
+	server := &Server{}
+	server.eventStackPool = pool
+	server.EnableTrace = true
+	reqCtx := &app.RequestContext{}
+	server.Core = &mockCore{
+		ctxPool: &sync.Pool{New: func() interface{} {
+			ti := traceinfo.NewTraceInfo()
+			ti.Stats().SetLevel(2)
+			reqCtx.SetTraceInfo(&mockTraceInfo{ti})
+			return reqCtx
+		}},
+		controller: &inStats.Controller{},
+	}
+	err := server.Serve(context.TODO(), mock.NewConn("GET /aaa HTTP/1.1\nHost: foobar.com\n\n"))
+	assert.True(t, errors.Is(err, errs.ErrShortConnection))
+	traceInfo := reqCtx.GetTraceInfo()
+	assert.False(t, traceInfo.Stats().GetEvent(stats.HTTPStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadHeaderStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadHeaderFinish).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadBodyStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadBodyFinish).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ServerHandleStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ServerHandleFinish).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.WriteStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.WriteFinish).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.HTTPFinish).IsNil())
+}
+
+func TestTraceEventReadHeaderError(t *testing.T) {
+	server := &Server{}
+	server.eventStackPool = pool
+	server.EnableTrace = true
+	reqCtx := &app.RequestContext{}
+	server.Core = &mockCore{
+		ctxPool: &sync.Pool{New: func() interface{} {
+			ti := traceinfo.NewTraceInfo()
+			ti.Stats().SetLevel(2)
+			reqCtx.SetTraceInfo(&mockTraceInfo{ti})
+			return reqCtx
+		}},
+		controller: &inStats.Controller{},
+	}
+	err := server.Serve(context.TODO(), mock.NewConn("ErrorFirstLine\r\n\r\n"))
+	assert.NotNil(t, err)
+	traceInfo := reqCtx.GetTraceInfo()
+	assert.False(t, traceInfo.Stats().GetEvent(stats.HTTPStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadHeaderStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadHeaderFinish).IsNil())
+	assert.Nil(t, traceInfo.Stats().GetEvent(stats.ReadBodyStart))
+	assert.Nil(t, traceInfo.Stats().GetEvent(stats.ReadBodyFinish))
+	assert.Nil(t, traceInfo.Stats().GetEvent(stats.ServerHandleStart))
+	assert.Nil(t, traceInfo.Stats().GetEvent(stats.ServerHandleFinish))
+	assert.Nil(t, traceInfo.Stats().GetEvent(stats.WriteStart))
+	assert.Nil(t, traceInfo.Stats().GetEvent(stats.WriteFinish))
+	assert.False(t, traceInfo.Stats().GetEvent(stats.HTTPFinish).IsNil())
+}
+
+func TestTraceEventReadBodyError(t *testing.T) {
+	server := &Server{}
+	server.eventStackPool = pool
+	server.EnableTrace = true
+	server.GetOnly = true
+	reqCtx := &app.RequestContext{}
+	server.Core = &mockCore{
+		ctxPool: &sync.Pool{New: func() interface{} {
+			ti := traceinfo.NewTraceInfo()
+			ti.Stats().SetLevel(2)
+			reqCtx.SetTraceInfo(&mockTraceInfo{ti})
+			return reqCtx
+		}},
+		controller: &inStats.Controller{},
+	}
+	err := server.Serve(context.TODO(), mock.NewConn("POST /aaa HTTP/1.1\nHost: foobar.com\nContent-Length: 5\nContent-Type: foo/bar\n\n12346\n\n"))
+	assert.NotNil(t, err)
+
+	traceInfo := reqCtx.GetTraceInfo()
+	assert.False(t, traceInfo.Stats().GetEvent(stats.HTTPStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadHeaderStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadHeaderFinish).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadBodyStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadBodyFinish).IsNil())
+	assert.Nil(t, traceInfo.Stats().GetEvent(stats.ServerHandleStart))
+	assert.Nil(t, traceInfo.Stats().GetEvent(stats.ServerHandleFinish))
+	assert.Nil(t, traceInfo.Stats().GetEvent(stats.WriteStart))
+	assert.Nil(t, traceInfo.Stats().GetEvent(stats.WriteFinish))
+	assert.False(t, traceInfo.Stats().GetEvent(stats.HTTPFinish).IsNil())
+}
+
+func TestTraceEventWriteError(t *testing.T) {
+	server := &Server{}
+	server.eventStackPool = pool
+	server.EnableTrace = true
+	reqCtx := &app.RequestContext{}
+	server.Core = &mockCore{
+		ctxPool: &sync.Pool{New: func() interface{} {
+			ti := traceinfo.NewTraceInfo()
+			ti.Stats().SetLevel(2)
+			reqCtx.SetTraceInfo(&mockTraceInfo{ti})
+			return reqCtx
+		}},
+		controller: &inStats.Controller{},
+	}
+	err := server.Serve(
+		context.TODO(),
+		&mockErrorWriter{
+			mock.NewConn("POST /aaa HTTP/1.1\nHost: foobar.com\nContent-Length: 5\nContent-Type: foo/bar\n\n12346\n\n"),
+		},
+	)
+	assert.NotNil(t, err)
+	traceInfo := reqCtx.GetTraceInfo()
+	assert.False(t, traceInfo.Stats().GetEvent(stats.HTTPStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadHeaderStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadHeaderFinish).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadBodyStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ReadBodyFinish).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ServerHandleStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.ServerHandleFinish).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.WriteStart).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.WriteFinish).IsNil())
+	assert.False(t, traceInfo.Stats().GetEvent(stats.HTTPFinish).IsNil())
+}
+
+func TestEventStack(t *testing.T) {
+	// Create a stack.
+	s := &eventStack{}
+	assert.True(t, s.isEmpty())
+
+	count := 0
+
+	// Push 10 events.
+	for i := 0; i < 10; i++ {
+		s.push(func(ti traceinfo.TraceInfo, err error) {
+			count += 1
+		})
+	}
+
+	assert.False(t, s.isEmpty())
+	// Pop 10 events and process them.
+	for last := s.pop(); last != nil; last = s.pop() {
+		last(nil, nil)
+	}
+
+	assert.DeepEqual(t, 10, count)
+
+	// Pop an empty stack.
+	e := s.pop()
+	if e != nil {
+		t.Fatalf("should be nil")
+	}
+}
+
+type mockCore struct {
+	ctxPool    *sync.Pool
+	controller tracer.Controller
+}
+
+func (m *mockCore) IsRunning() bool {
+	return false
+}
+
+func (m *mockCore) GetCtxPool() *sync.Pool {
+	return m.ctxPool
+}
+
+func (m *mockCore) ServeHTTP(c context.Context, ctx *app.RequestContext) {}
+
+func (m *mockCore) GetTracer() tracer.Controller {
+	return m.controller
+}
+
+type mockTraceInfo struct {
+	traceinfo.TraceInfo
+}
+
+func (m *mockTraceInfo) Reset() {}
+
+type mockErrorWriter struct {
+	network.Conn
+}
+
+func (errorWriter *mockErrorWriter) Flush() error {
+	return errors.New("error")
+}
diff --git a/pkg/protocol/http1/server_timing_test.go b/pkg/protocol/http1/server_timing_test.go
new file mode 100644
index 0000000..144bb3e
--- /dev/null
+++ b/pkg/protocol/http1/server_timing_test.go
@@ -0,0 +1,56 @@
+/*
+ * Copyright 2023 CloudWeGo Authors
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package http1
+
+import (
+	"context"
+	"fmt"
+	"sync"
+	"testing"
+
+	inStats "github.com/cloudwego/hertz/internal/stats"
+	"github.com/cloudwego/hertz/pkg/app"
+	"github.com/cloudwego/hertz/pkg/common/test/mock"
+	"github.com/cloudwego/hertz/pkg/common/tracer/traceinfo"
+)
+
+func BenchmarkServer_Serve(b *testing.B) {
+	server := &Server{}
+	server.eventStackPool = &sync.Pool{
+		New: func() interface{} {
+			return &eventStack{}
+		},
+	}
+	server.EnableTrace = true
+	reqCtx := &app.RequestContext{}
+	server.Core = &mockCore{
+		ctxPool: &sync.Pool{New: func() interface{} {
+			ti := traceinfo.NewTraceInfo()
+			ti.Stats().SetLevel(2)
+			reqCtx.SetTraceInfo(&mockTraceInfo{ti})
+			return reqCtx
+		}},
+		controller: &inStats.Controller{},
+	}
+	err := server.Serve(context.TODO(), mock.NewConn("GET /aaa HTTP/1.1\nHost: foobar.com\n\n"))
+	if err != nil {
+		fmt.Println(err.Error())
+	}
+	for i := 0; i < b.N; i++ {
+		server.Serve(context.TODO(), mock.NewConn("GET /aaa HTTP/1.1\nHost: foobar.com\n\n"))
+	}
+}