tlogger.go 5.7 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244
  1. /*
  2. *
  3. * Copyright 2020 gRPC authors.
  4. *
  5. * Licensed under the Apache License, Version 2.0 (the "License");
  6. * you may not use this file except in compliance with the License.
  7. * You may obtain a copy of the License at
  8. *
  9. * http://www.apache.org/licenses/LICENSE-2.0
  10. *
  11. * Unless required by applicable law or agreed to in writing, software
  12. * distributed under the License is distributed on an "AS IS" BASIS,
  13. * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  14. * See the License for the specific language governing permissions and
  15. * limitations under the License.
  16. *
  17. */
  18. package grpctest
  19. import (
  20. "errors"
  21. "fmt"
  22. "os"
  23. "regexp"
  24. "runtime/debug"
  25. "strconv"
  26. "strings"
  27. "sync"
  28. "testing"
  29. "google.golang.org/grpc/grpclog"
  30. )
  31. // TLogger serves as the grpclog logger and is the interface through which
  32. // expected errors are declared in tests.
  33. var TLogger *tLogger
  34. const callingFrame = 4
  35. type logType int
  36. const (
  37. logLog logType = iota
  38. errorLog
  39. fatalLog
  40. )
  41. type tLogger struct {
  42. v int
  43. t *testing.T
  44. initialized bool
  45. m sync.Mutex // protects errors
  46. errors map[*regexp.Regexp]int
  47. }
  48. func init() {
  49. TLogger = &tLogger{errors: map[*regexp.Regexp]int{}}
  50. vLevel := os.Getenv("GRPC_GO_LOG_VERBOSITY_LEVEL")
  51. if vl, err := strconv.Atoi(vLevel); err == nil {
  52. TLogger.v = vl
  53. }
  54. }
  55. // getStackFrame gets, from the stack byte string, the appropriate stack frame.
  56. func getStackFrame(stack []byte, frame int) (string, error) {
  57. s := strings.Split(string(stack), "\n")
  58. if frame >= (len(s)-1)/2 {
  59. return "", errors.New("frame request out-of-bounds")
  60. }
  61. split := strings.Split(strings.Fields(s[(frame*2)+2][1:])[0], "/")
  62. return fmt.Sprintf("%v:", split[len(split)-1]), nil
  63. }
  64. // log logs the message with the specified parameters to the tLogger.
  65. func (g *tLogger) log(ltype logType, depth int, format string, args ...interface{}) {
  66. s := debug.Stack()
  67. prefix, err := getStackFrame(s, callingFrame+depth)
  68. args = append([]interface{}{prefix}, args...)
  69. if err != nil {
  70. g.t.Error(err)
  71. return
  72. }
  73. if format == "" {
  74. switch ltype {
  75. case errorLog:
  76. // fmt.Sprintln is used rather than fmt.Sprint because t.Log uses fmt.Sprintln behavior.
  77. if g.expected(fmt.Sprintln(args...)) {
  78. g.t.Log(args...)
  79. } else {
  80. g.t.Error(args...)
  81. }
  82. case fatalLog:
  83. panic(fmt.Sprint(args...))
  84. default:
  85. g.t.Log(args...)
  86. }
  87. } else {
  88. format = "%v " + format
  89. switch ltype {
  90. case errorLog:
  91. if g.expected(fmt.Sprintf(format, args...)) {
  92. g.t.Logf(format, args...)
  93. } else {
  94. g.t.Errorf(format, args...)
  95. }
  96. case fatalLog:
  97. panic(fmt.Sprintf(format, args...))
  98. default:
  99. g.t.Logf(format, args...)
  100. }
  101. }
  102. }
  103. // Update updates the testing.T that the testing logger logs to. Should be done
  104. // before every test. It also initializes the tLogger if it has not already.
  105. func (g *tLogger) Update(t *testing.T) {
  106. if !g.initialized {
  107. grpclog.SetLoggerV2(TLogger)
  108. g.initialized = true
  109. }
  110. g.t = t
  111. g.m.Lock()
  112. defer g.m.Unlock()
  113. g.errors = map[*regexp.Regexp]int{}
  114. }
  115. // ExpectError declares an error to be expected. For the next test, the first
  116. // error log matching the expression (using FindString) will not cause the test
  117. // to fail. "For the next test" includes all the time until the next call to
  118. // Update(). Note that if an expected error is not encountered, this will cause
  119. // the test to fail.
  120. func (g *tLogger) ExpectError(expr string) {
  121. g.ExpectErrorN(expr, 1)
  122. }
  123. // ExpectErrorN declares an error to be expected n times.
  124. func (g *tLogger) ExpectErrorN(expr string, n int) {
  125. re, err := regexp.Compile(expr)
  126. if err != nil {
  127. g.t.Error(err)
  128. return
  129. }
  130. g.m.Lock()
  131. defer g.m.Unlock()
  132. g.errors[re] += n
  133. }
  134. // EndTest checks if expected errors were not encountered.
  135. func (g *tLogger) EndTest(t *testing.T) {
  136. g.m.Lock()
  137. defer g.m.Unlock()
  138. for re, count := range g.errors {
  139. if count > 0 {
  140. t.Errorf("Expected error '%v' not encountered", re.String())
  141. }
  142. }
  143. g.errors = map[*regexp.Regexp]int{}
  144. }
  145. // expected determines if the error string is protected or not.
  146. func (g *tLogger) expected(s string) bool {
  147. g.m.Lock()
  148. defer g.m.Unlock()
  149. for re, count := range g.errors {
  150. if re.FindStringIndex(s) != nil {
  151. g.errors[re]--
  152. if count <= 1 {
  153. delete(g.errors, re)
  154. }
  155. return true
  156. }
  157. }
  158. return false
  159. }
  160. func (g *tLogger) Info(args ...interface{}) {
  161. g.log(logLog, 0, "", args...)
  162. }
  163. func (g *tLogger) Infoln(args ...interface{}) {
  164. g.log(logLog, 0, "", args...)
  165. }
  166. func (g *tLogger) Infof(format string, args ...interface{}) {
  167. g.log(logLog, 0, format, args...)
  168. }
  169. func (g *tLogger) InfoDepth(depth int, args ...interface{}) {
  170. g.log(logLog, depth, "", args...)
  171. }
  172. func (g *tLogger) Warning(args ...interface{}) {
  173. g.log(logLog, 0, "", args...)
  174. }
  175. func (g *tLogger) Warningln(args ...interface{}) {
  176. g.log(logLog, 0, "", args...)
  177. }
  178. func (g *tLogger) Warningf(format string, args ...interface{}) {
  179. g.log(logLog, 0, format, args...)
  180. }
  181. func (g *tLogger) WarningDepth(depth int, args ...interface{}) {
  182. g.log(logLog, depth, "", args...)
  183. }
  184. func (g *tLogger) Error(args ...interface{}) {
  185. g.log(errorLog, 0, "", args...)
  186. }
  187. func (g *tLogger) Errorln(args ...interface{}) {
  188. g.log(errorLog, 0, "", args...)
  189. }
  190. func (g *tLogger) Errorf(format string, args ...interface{}) {
  191. g.log(errorLog, 0, format, args...)
  192. }
  193. func (g *tLogger) ErrorDepth(depth int, args ...interface{}) {
  194. g.log(errorLog, depth, "", args...)
  195. }
  196. func (g *tLogger) Fatal(args ...interface{}) {
  197. g.log(fatalLog, 0, "", args...)
  198. }
  199. func (g *tLogger) Fatalln(args ...interface{}) {
  200. g.log(fatalLog, 0, "", args...)
  201. }
  202. func (g *tLogger) Fatalf(format string, args ...interface{}) {
  203. g.log(fatalLog, 0, format, args...)
  204. }
  205. func (g *tLogger) FatalDepth(depth int, args ...interface{}) {
  206. g.log(fatalLog, depth, "", args...)
  207. }
  208. func (g *tLogger) V(l int) bool {
  209. return l <= g.v
  210. }