hook_test.go 5.5 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197
  1. package redis
  2. import (
  3. "context"
  4. "log"
  5. "strings"
  6. "testing"
  7. "time"
  8. red "github.com/go-redis/redis/v8"
  9. "github.com/stretchr/testify/assert"
  10. "github.com/zeromicro/go-zero/core/logx"
  11. ztrace "github.com/zeromicro/go-zero/core/trace"
  12. tracesdk "go.opentelemetry.io/otel/trace"
  13. )
  14. func TestHookProcessCase1(t *testing.T) {
  15. ztrace.StartAgent(ztrace.Config{
  16. Name: "go-zero-test",
  17. Endpoint: "http://localhost:14268/api/traces",
  18. Batcher: "jaeger",
  19. Sampler: 1.0,
  20. })
  21. defer ztrace.StopAgent()
  22. writer := log.Writer()
  23. var buf strings.Builder
  24. log.SetOutput(&buf)
  25. defer log.SetOutput(writer)
  26. ctx, err := durationHook.BeforeProcess(context.Background(), red.NewCmd(context.Background()))
  27. if err != nil {
  28. t.Fatal(err)
  29. }
  30. assert.Nil(t, durationHook.AfterProcess(ctx, red.NewCmd(context.Background())))
  31. assert.False(t, strings.Contains(buf.String(), "slow"))
  32. assert.Equal(t, "redis", tracesdk.SpanFromContext(ctx).(interface{ Name() string }).Name())
  33. }
  34. func TestHookProcessCase2(t *testing.T) {
  35. ztrace.StartAgent(ztrace.Config{
  36. Name: "go-zero-test",
  37. Endpoint: "http://localhost:14268/api/traces",
  38. Batcher: "jaeger",
  39. Sampler: 1.0,
  40. })
  41. defer ztrace.StopAgent()
  42. w, restore := injectLog()
  43. defer restore()
  44. ctx, err := durationHook.BeforeProcess(context.Background(), red.NewCmd(context.Background()))
  45. if err != nil {
  46. t.Fatal(err)
  47. }
  48. assert.Equal(t, "redis", tracesdk.SpanFromContext(ctx).(interface{ Name() string }).Name())
  49. time.Sleep(slowThreshold.Load() + time.Millisecond)
  50. assert.Nil(t, durationHook.AfterProcess(ctx, red.NewCmd(context.Background(), "foo", "bar")))
  51. assert.True(t, strings.Contains(w.String(), "slow"))
  52. assert.True(t, strings.Contains(w.String(), "trace"))
  53. assert.True(t, strings.Contains(w.String(), "span"))
  54. }
  55. func TestHookProcessCase3(t *testing.T) {
  56. writer := log.Writer()
  57. var buf strings.Builder
  58. log.SetOutput(&buf)
  59. defer log.SetOutput(writer)
  60. assert.Nil(t, durationHook.AfterProcess(context.Background(), red.NewCmd(context.Background())))
  61. assert.True(t, buf.Len() == 0)
  62. }
  63. func TestHookProcessCase4(t *testing.T) {
  64. writer := log.Writer()
  65. var buf strings.Builder
  66. log.SetOutput(&buf)
  67. defer log.SetOutput(writer)
  68. ctx := context.WithValue(context.Background(), startTimeKey, "foo")
  69. assert.Nil(t, durationHook.AfterProcess(ctx, red.NewCmd(context.Background())))
  70. assert.True(t, buf.Len() == 0)
  71. }
  72. func TestHookProcessPipelineCase1(t *testing.T) {
  73. writer := log.Writer()
  74. var buf strings.Builder
  75. log.SetOutput(&buf)
  76. defer log.SetOutput(writer)
  77. _, err := durationHook.BeforeProcessPipeline(context.Background(), []red.Cmder{})
  78. assert.NoError(t, err)
  79. ctx, err := durationHook.BeforeProcessPipeline(context.Background(), []red.Cmder{
  80. red.NewCmd(context.Background()),
  81. })
  82. assert.NoError(t, err)
  83. assert.Equal(t, "redis", tracesdk.SpanFromContext(ctx).(interface{ Name() string }).Name())
  84. assert.NoError(t, durationHook.AfterProcessPipeline(ctx, []red.Cmder{}))
  85. assert.NoError(t, durationHook.AfterProcessPipeline(ctx, []red.Cmder{
  86. red.NewCmd(context.Background()),
  87. }))
  88. assert.False(t, strings.Contains(buf.String(), "slow"))
  89. }
  90. func TestHookProcessPipelineCase2(t *testing.T) {
  91. ztrace.StartAgent(ztrace.Config{
  92. Name: "go-zero-test",
  93. Endpoint: "http://localhost:14268/api/traces",
  94. Batcher: "jaeger",
  95. Sampler: 1.0,
  96. })
  97. defer ztrace.StopAgent()
  98. w, restore := injectLog()
  99. defer restore()
  100. ctx, err := durationHook.BeforeProcessPipeline(context.Background(), []red.Cmder{
  101. red.NewCmd(context.Background()),
  102. })
  103. assert.NoError(t, err)
  104. assert.Equal(t, "redis", tracesdk.SpanFromContext(ctx).(interface{ Name() string }).Name())
  105. time.Sleep(slowThreshold.Load() + time.Millisecond)
  106. assert.Nil(t, durationHook.AfterProcessPipeline(ctx, []red.Cmder{
  107. red.NewCmd(context.Background(), "foo", "bar"),
  108. }))
  109. assert.True(t, strings.Contains(w.String(), "slow"))
  110. assert.True(t, strings.Contains(w.String(), "trace"))
  111. assert.True(t, strings.Contains(w.String(), "span"))
  112. }
  113. func TestHookProcessPipelineCase3(t *testing.T) {
  114. w, restore := injectLog()
  115. defer restore()
  116. assert.Nil(t, durationHook.AfterProcessPipeline(context.Background(), []red.Cmder{
  117. red.NewCmd(context.Background()),
  118. }))
  119. assert.True(t, len(w.String()) == 0)
  120. }
  121. func TestHookProcessPipelineCase4(t *testing.T) {
  122. w, restore := injectLog()
  123. defer restore()
  124. ctx := context.WithValue(context.Background(), startTimeKey, "foo")
  125. assert.Nil(t, durationHook.AfterProcessPipeline(ctx, []red.Cmder{
  126. red.NewCmd(context.Background()),
  127. }))
  128. assert.True(t, len(w.String()) == 0)
  129. }
  130. func TestHookProcessPipelineCase5(t *testing.T) {
  131. writer := log.Writer()
  132. var buf strings.Builder
  133. log.SetOutput(&buf)
  134. defer log.SetOutput(writer)
  135. ctx := context.WithValue(context.Background(), startTimeKey, "foo")
  136. assert.Nil(t, durationHook.AfterProcessPipeline(ctx, []red.Cmder{
  137. red.NewCmd(context.Background()),
  138. }))
  139. assert.True(t, buf.Len() == 0)
  140. }
  141. func TestLogDuration(t *testing.T) {
  142. w, restore := injectLog()
  143. defer restore()
  144. logDuration(context.Background(), []red.Cmder{
  145. red.NewCmd(context.Background(), "get", "foo"),
  146. }, 1*time.Second)
  147. assert.True(t, strings.Contains(w.String(), "get foo"))
  148. logDuration(context.Background(), []red.Cmder{
  149. red.NewCmd(context.Background(), "get", "foo"),
  150. red.NewCmd(context.Background(), "set", "bar", 0),
  151. }, 1*time.Second)
  152. assert.True(t, strings.Contains(w.String(), `get foo\nset bar 0`))
  153. }
  154. func injectLog() (r *strings.Builder, restore func()) {
  155. var buf strings.Builder
  156. w := logx.NewWriter(&buf)
  157. o := logx.Reset()
  158. logx.SetWriter(w)
  159. return &buf, func() {
  160. logx.Reset()
  161. logx.SetWriter(o)
  162. }
  163. }