method_logger.go 11 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435
  1. /*
  2. *
  3. * Copyright 2018 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 binarylog
  19. import (
  20. "net"
  21. "strings"
  22. "sync/atomic"
  23. "time"
  24. "github.com/golang/protobuf/proto"
  25. "github.com/golang/protobuf/ptypes"
  26. pb "google.golang.org/grpc/binarylog/grpc_binarylog_v1"
  27. "google.golang.org/grpc/metadata"
  28. "google.golang.org/grpc/status"
  29. )
  30. type callIDGenerator struct {
  31. id uint64
  32. }
  33. func (g *callIDGenerator) next() uint64 {
  34. id := atomic.AddUint64(&g.id, 1)
  35. return id
  36. }
  37. // reset is for testing only, and doesn't need to be thread safe.
  38. func (g *callIDGenerator) reset() {
  39. g.id = 0
  40. }
  41. var idGen callIDGenerator
  42. // MethodLogger is the sub-logger for each method.
  43. type MethodLogger interface {
  44. Log(LogEntryConfig)
  45. }
  46. // TruncatingMethodLogger is a method logger that truncates headers and messages
  47. // based on configured fields.
  48. type TruncatingMethodLogger struct {
  49. headerMaxLen, messageMaxLen uint64
  50. callID uint64
  51. idWithinCallGen *callIDGenerator
  52. sink Sink // TODO(blog): make this plugable.
  53. }
  54. // NewTruncatingMethodLogger returns a new truncating method logger.
  55. func NewTruncatingMethodLogger(h, m uint64) *TruncatingMethodLogger {
  56. return &TruncatingMethodLogger{
  57. headerMaxLen: h,
  58. messageMaxLen: m,
  59. callID: idGen.next(),
  60. idWithinCallGen: &callIDGenerator{},
  61. sink: DefaultSink, // TODO(blog): make it plugable.
  62. }
  63. }
  64. // Build is an internal only method for building the proto message out of the
  65. // input event. It's made public to enable other library to reuse as much logic
  66. // in TruncatingMethodLogger as possible.
  67. func (ml *TruncatingMethodLogger) Build(c LogEntryConfig) *pb.GrpcLogEntry {
  68. m := c.toProto()
  69. timestamp, _ := ptypes.TimestampProto(time.Now())
  70. m.Timestamp = timestamp
  71. m.CallId = ml.callID
  72. m.SequenceIdWithinCall = ml.idWithinCallGen.next()
  73. switch pay := m.Payload.(type) {
  74. case *pb.GrpcLogEntry_ClientHeader:
  75. m.PayloadTruncated = ml.truncateMetadata(pay.ClientHeader.GetMetadata())
  76. case *pb.GrpcLogEntry_ServerHeader:
  77. m.PayloadTruncated = ml.truncateMetadata(pay.ServerHeader.GetMetadata())
  78. case *pb.GrpcLogEntry_Message:
  79. m.PayloadTruncated = ml.truncateMessage(pay.Message)
  80. }
  81. return m
  82. }
  83. // Log creates a proto binary log entry, and logs it to the sink.
  84. func (ml *TruncatingMethodLogger) Log(c LogEntryConfig) {
  85. ml.sink.Write(ml.Build(c))
  86. }
  87. func (ml *TruncatingMethodLogger) truncateMetadata(mdPb *pb.Metadata) (truncated bool) {
  88. if ml.headerMaxLen == maxUInt {
  89. return false
  90. }
  91. var (
  92. bytesLimit = ml.headerMaxLen
  93. index int
  94. )
  95. // At the end of the loop, index will be the first entry where the total
  96. // size is greater than the limit:
  97. //
  98. // len(entry[:index]) <= ml.hdr && len(entry[:index+1]) > ml.hdr.
  99. for ; index < len(mdPb.Entry); index++ {
  100. entry := mdPb.Entry[index]
  101. if entry.Key == "grpc-trace-bin" {
  102. // "grpc-trace-bin" is a special key. It's kept in the log entry,
  103. // but not counted towards the size limit.
  104. continue
  105. }
  106. currentEntryLen := uint64(len(entry.Value))
  107. if currentEntryLen > bytesLimit {
  108. break
  109. }
  110. bytesLimit -= currentEntryLen
  111. }
  112. truncated = index < len(mdPb.Entry)
  113. mdPb.Entry = mdPb.Entry[:index]
  114. return truncated
  115. }
  116. func (ml *TruncatingMethodLogger) truncateMessage(msgPb *pb.Message) (truncated bool) {
  117. if ml.messageMaxLen == maxUInt {
  118. return false
  119. }
  120. if ml.messageMaxLen >= uint64(len(msgPb.Data)) {
  121. return false
  122. }
  123. msgPb.Data = msgPb.Data[:ml.messageMaxLen]
  124. return true
  125. }
  126. // LogEntryConfig represents the configuration for binary log entry.
  127. type LogEntryConfig interface {
  128. toProto() *pb.GrpcLogEntry
  129. }
  130. // ClientHeader configs the binary log entry to be a ClientHeader entry.
  131. type ClientHeader struct {
  132. OnClientSide bool
  133. Header metadata.MD
  134. MethodName string
  135. Authority string
  136. Timeout time.Duration
  137. // PeerAddr is required only when it's on server side.
  138. PeerAddr net.Addr
  139. }
  140. func (c *ClientHeader) toProto() *pb.GrpcLogEntry {
  141. // This function doesn't need to set all the fields (e.g. seq ID). The Log
  142. // function will set the fields when necessary.
  143. clientHeader := &pb.ClientHeader{
  144. Metadata: mdToMetadataProto(c.Header),
  145. MethodName: c.MethodName,
  146. Authority: c.Authority,
  147. }
  148. if c.Timeout > 0 {
  149. clientHeader.Timeout = ptypes.DurationProto(c.Timeout)
  150. }
  151. ret := &pb.GrpcLogEntry{
  152. Type: pb.GrpcLogEntry_EVENT_TYPE_CLIENT_HEADER,
  153. Payload: &pb.GrpcLogEntry_ClientHeader{
  154. ClientHeader: clientHeader,
  155. },
  156. }
  157. if c.OnClientSide {
  158. ret.Logger = pb.GrpcLogEntry_LOGGER_CLIENT
  159. } else {
  160. ret.Logger = pb.GrpcLogEntry_LOGGER_SERVER
  161. }
  162. if c.PeerAddr != nil {
  163. ret.Peer = addrToProto(c.PeerAddr)
  164. }
  165. return ret
  166. }
  167. // ServerHeader configs the binary log entry to be a ServerHeader entry.
  168. type ServerHeader struct {
  169. OnClientSide bool
  170. Header metadata.MD
  171. // PeerAddr is required only when it's on client side.
  172. PeerAddr net.Addr
  173. }
  174. func (c *ServerHeader) toProto() *pb.GrpcLogEntry {
  175. ret := &pb.GrpcLogEntry{
  176. Type: pb.GrpcLogEntry_EVENT_TYPE_SERVER_HEADER,
  177. Payload: &pb.GrpcLogEntry_ServerHeader{
  178. ServerHeader: &pb.ServerHeader{
  179. Metadata: mdToMetadataProto(c.Header),
  180. },
  181. },
  182. }
  183. if c.OnClientSide {
  184. ret.Logger = pb.GrpcLogEntry_LOGGER_CLIENT
  185. } else {
  186. ret.Logger = pb.GrpcLogEntry_LOGGER_SERVER
  187. }
  188. if c.PeerAddr != nil {
  189. ret.Peer = addrToProto(c.PeerAddr)
  190. }
  191. return ret
  192. }
  193. // ClientMessage configs the binary log entry to be a ClientMessage entry.
  194. type ClientMessage struct {
  195. OnClientSide bool
  196. // Message can be a proto.Message or []byte. Other messages formats are not
  197. // supported.
  198. Message interface{}
  199. }
  200. func (c *ClientMessage) toProto() *pb.GrpcLogEntry {
  201. var (
  202. data []byte
  203. err error
  204. )
  205. if m, ok := c.Message.(proto.Message); ok {
  206. data, err = proto.Marshal(m)
  207. if err != nil {
  208. grpclogLogger.Infof("binarylogging: failed to marshal proto message: %v", err)
  209. }
  210. } else if b, ok := c.Message.([]byte); ok {
  211. data = b
  212. } else {
  213. grpclogLogger.Infof("binarylogging: message to log is neither proto.message nor []byte")
  214. }
  215. ret := &pb.GrpcLogEntry{
  216. Type: pb.GrpcLogEntry_EVENT_TYPE_CLIENT_MESSAGE,
  217. Payload: &pb.GrpcLogEntry_Message{
  218. Message: &pb.Message{
  219. Length: uint32(len(data)),
  220. Data: data,
  221. },
  222. },
  223. }
  224. if c.OnClientSide {
  225. ret.Logger = pb.GrpcLogEntry_LOGGER_CLIENT
  226. } else {
  227. ret.Logger = pb.GrpcLogEntry_LOGGER_SERVER
  228. }
  229. return ret
  230. }
  231. // ServerMessage configs the binary log entry to be a ServerMessage entry.
  232. type ServerMessage struct {
  233. OnClientSide bool
  234. // Message can be a proto.Message or []byte. Other messages formats are not
  235. // supported.
  236. Message interface{}
  237. }
  238. func (c *ServerMessage) toProto() *pb.GrpcLogEntry {
  239. var (
  240. data []byte
  241. err error
  242. )
  243. if m, ok := c.Message.(proto.Message); ok {
  244. data, err = proto.Marshal(m)
  245. if err != nil {
  246. grpclogLogger.Infof("binarylogging: failed to marshal proto message: %v", err)
  247. }
  248. } else if b, ok := c.Message.([]byte); ok {
  249. data = b
  250. } else {
  251. grpclogLogger.Infof("binarylogging: message to log is neither proto.message nor []byte")
  252. }
  253. ret := &pb.GrpcLogEntry{
  254. Type: pb.GrpcLogEntry_EVENT_TYPE_SERVER_MESSAGE,
  255. Payload: &pb.GrpcLogEntry_Message{
  256. Message: &pb.Message{
  257. Length: uint32(len(data)),
  258. Data: data,
  259. },
  260. },
  261. }
  262. if c.OnClientSide {
  263. ret.Logger = pb.GrpcLogEntry_LOGGER_CLIENT
  264. } else {
  265. ret.Logger = pb.GrpcLogEntry_LOGGER_SERVER
  266. }
  267. return ret
  268. }
  269. // ClientHalfClose configs the binary log entry to be a ClientHalfClose entry.
  270. type ClientHalfClose struct {
  271. OnClientSide bool
  272. }
  273. func (c *ClientHalfClose) toProto() *pb.GrpcLogEntry {
  274. ret := &pb.GrpcLogEntry{
  275. Type: pb.GrpcLogEntry_EVENT_TYPE_CLIENT_HALF_CLOSE,
  276. Payload: nil, // No payload here.
  277. }
  278. if c.OnClientSide {
  279. ret.Logger = pb.GrpcLogEntry_LOGGER_CLIENT
  280. } else {
  281. ret.Logger = pb.GrpcLogEntry_LOGGER_SERVER
  282. }
  283. return ret
  284. }
  285. // ServerTrailer configs the binary log entry to be a ServerTrailer entry.
  286. type ServerTrailer struct {
  287. OnClientSide bool
  288. Trailer metadata.MD
  289. // Err is the status error.
  290. Err error
  291. // PeerAddr is required only when it's on client side and the RPC is trailer
  292. // only.
  293. PeerAddr net.Addr
  294. }
  295. func (c *ServerTrailer) toProto() *pb.GrpcLogEntry {
  296. st, ok := status.FromError(c.Err)
  297. if !ok {
  298. grpclogLogger.Info("binarylogging: error in trailer is not a status error")
  299. }
  300. var (
  301. detailsBytes []byte
  302. err error
  303. )
  304. stProto := st.Proto()
  305. if stProto != nil && len(stProto.Details) != 0 {
  306. detailsBytes, err = proto.Marshal(stProto)
  307. if err != nil {
  308. grpclogLogger.Infof("binarylogging: failed to marshal status proto: %v", err)
  309. }
  310. }
  311. ret := &pb.GrpcLogEntry{
  312. Type: pb.GrpcLogEntry_EVENT_TYPE_SERVER_TRAILER,
  313. Payload: &pb.GrpcLogEntry_Trailer{
  314. Trailer: &pb.Trailer{
  315. Metadata: mdToMetadataProto(c.Trailer),
  316. StatusCode: uint32(st.Code()),
  317. StatusMessage: st.Message(),
  318. StatusDetails: detailsBytes,
  319. },
  320. },
  321. }
  322. if c.OnClientSide {
  323. ret.Logger = pb.GrpcLogEntry_LOGGER_CLIENT
  324. } else {
  325. ret.Logger = pb.GrpcLogEntry_LOGGER_SERVER
  326. }
  327. if c.PeerAddr != nil {
  328. ret.Peer = addrToProto(c.PeerAddr)
  329. }
  330. return ret
  331. }
  332. // Cancel configs the binary log entry to be a Cancel entry.
  333. type Cancel struct {
  334. OnClientSide bool
  335. }
  336. func (c *Cancel) toProto() *pb.GrpcLogEntry {
  337. ret := &pb.GrpcLogEntry{
  338. Type: pb.GrpcLogEntry_EVENT_TYPE_CANCEL,
  339. Payload: nil,
  340. }
  341. if c.OnClientSide {
  342. ret.Logger = pb.GrpcLogEntry_LOGGER_CLIENT
  343. } else {
  344. ret.Logger = pb.GrpcLogEntry_LOGGER_SERVER
  345. }
  346. return ret
  347. }
  348. // metadataKeyOmit returns whether the metadata entry with this key should be
  349. // omitted.
  350. func metadataKeyOmit(key string) bool {
  351. switch key {
  352. case "lb-token", ":path", ":authority", "content-encoding", "content-type", "user-agent", "te":
  353. return true
  354. case "grpc-trace-bin": // grpc-trace-bin is special because it's visiable to users.
  355. return false
  356. }
  357. return strings.HasPrefix(key, "grpc-")
  358. }
  359. func mdToMetadataProto(md metadata.MD) *pb.Metadata {
  360. ret := &pb.Metadata{}
  361. for k, vv := range md {
  362. if metadataKeyOmit(k) {
  363. continue
  364. }
  365. for _, v := range vv {
  366. ret.Entry = append(ret.Entry,
  367. &pb.MetadataEntry{
  368. Key: k,
  369. Value: []byte(v),
  370. },
  371. )
  372. }
  373. }
  374. return ret
  375. }
  376. func addrToProto(addr net.Addr) *pb.Address {
  377. ret := &pb.Address{}
  378. switch a := addr.(type) {
  379. case *net.TCPAddr:
  380. if a.IP.To4() != nil {
  381. ret.Type = pb.Address_TYPE_IPV4
  382. } else if a.IP.To16() != nil {
  383. ret.Type = pb.Address_TYPE_IPV6
  384. } else {
  385. ret.Type = pb.Address_TYPE_UNKNOWN
  386. // Do not set address and port fields.
  387. break
  388. }
  389. ret.Address = a.IP.String()
  390. ret.IpPort = uint32(a.Port)
  391. case *net.UnixAddr:
  392. ret.Type = pb.Address_TYPE_UNIX
  393. ret.Address = a.String()
  394. default:
  395. ret.Type = pb.Address_TYPE_UNKNOWN
  396. }
  397. return ret
  398. }