hook_test.go 5.3 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194
  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. ctx, err := durationHook.BeforeProcessPipeline(context.Background(), []red.Cmder{
  78. red.NewCmd(context.Background()),
  79. })
  80. assert.NoError(t, err)
  81. assert.Equal(t, "redis", tracesdk.SpanFromContext(ctx).(interface{ Name() string }).Name())
  82. assert.Nil(t, durationHook.AfterProcessPipeline(ctx, []red.Cmder{
  83. red.NewCmd(context.Background()),
  84. }))
  85. assert.False(t, strings.Contains(buf.String(), "slow"))
  86. }
  87. func TestHookProcessPipelineCase2(t *testing.T) {
  88. ztrace.StartAgent(ztrace.Config{
  89. Name: "go-zero-test",
  90. Endpoint: "http://localhost:14268/api/traces",
  91. Batcher: "jaeger",
  92. Sampler: 1.0,
  93. })
  94. defer ztrace.StopAgent()
  95. w, restore := injectLog()
  96. defer restore()
  97. ctx, err := durationHook.BeforeProcessPipeline(context.Background(), []red.Cmder{
  98. red.NewCmd(context.Background()),
  99. })
  100. assert.NoError(t, err)
  101. assert.Equal(t, "redis", tracesdk.SpanFromContext(ctx).(interface{ Name() string }).Name())
  102. time.Sleep(slowThreshold.Load() + time.Millisecond)
  103. assert.Nil(t, durationHook.AfterProcessPipeline(ctx, []red.Cmder{
  104. red.NewCmd(context.Background(), "foo", "bar"),
  105. }))
  106. assert.True(t, strings.Contains(w.String(), "slow"))
  107. assert.True(t, strings.Contains(w.String(), "trace"))
  108. assert.True(t, strings.Contains(w.String(), "span"))
  109. }
  110. func TestHookProcessPipelineCase3(t *testing.T) {
  111. w, restore := injectLog()
  112. defer restore()
  113. assert.Nil(t, durationHook.AfterProcessPipeline(context.Background(), []red.Cmder{
  114. red.NewCmd(context.Background()),
  115. }))
  116. assert.True(t, len(w.String()) == 0)
  117. }
  118. func TestHookProcessPipelineCase4(t *testing.T) {
  119. w, restore := injectLog()
  120. defer restore()
  121. ctx := context.WithValue(context.Background(), startTimeKey, "foo")
  122. assert.Nil(t, durationHook.AfterProcessPipeline(ctx, []red.Cmder{
  123. red.NewCmd(context.Background()),
  124. }))
  125. assert.True(t, len(w.String()) == 0)
  126. }
  127. func TestHookProcessPipelineCase5(t *testing.T) {
  128. writer := log.Writer()
  129. var buf strings.Builder
  130. log.SetOutput(&buf)
  131. defer log.SetOutput(writer)
  132. ctx := context.WithValue(context.Background(), startTimeKey, "foo")
  133. assert.Nil(t, durationHook.AfterProcessPipeline(ctx, []red.Cmder{
  134. red.NewCmd(context.Background()),
  135. }))
  136. assert.True(t, buf.Len() == 0)
  137. }
  138. func TestLogDuration(t *testing.T) {
  139. w, restore := injectLog()
  140. defer restore()
  141. logDuration(context.Background(), []red.Cmder{
  142. red.NewCmd(context.Background(), "get", "foo"),
  143. }, 1*time.Second)
  144. assert.True(t, strings.Contains(w.String(), "get foo"))
  145. logDuration(context.Background(), []red.Cmder{
  146. red.NewCmd(context.Background(), "get", "foo"),
  147. red.NewCmd(context.Background(), "set", "bar", 0),
  148. }, 1*time.Second)
  149. assert.True(t, strings.Contains(w.String(), `get foo\nset bar 0`))
  150. }
  151. func injectLog() (r *strings.Builder, restore func()) {
  152. var buf strings.Builder
  153. w := logx.NewWriter(&buf)
  154. o := logx.Reset()
  155. logx.SetWriter(w)
  156. return &buf, func() {
  157. logx.Reset()
  158. logx.SetWriter(o)
  159. }
  160. }