logging.go 31 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921
  1. // Copyright 2016 Google LLC
  2. //
  3. // Licensed under the Apache License, Version 2.0 (the "License");
  4. // you may not use this file except in compliance with the License.
  5. // You may obtain a copy of the License at
  6. //
  7. // http://www.apache.org/licenses/LICENSE-2.0
  8. //
  9. // Unless required by applicable law or agreed to in writing, software
  10. // distributed under the License is distributed on an "AS IS" BASIS,
  11. // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  12. // See the License for the specific language governing permissions and
  13. // limitations under the License.
  14. // API/gRPC features intentionally missing from this client:
  15. // - You cannot have the server pick the time of the entry. This client
  16. // always sends a time.
  17. // - There is no way to provide a protocol buffer payload.
  18. // - No support for the "partial success" feature when writing log entries.
  19. // TODO(jba): test whether forward-slash characters in the log ID must be URL-encoded.
  20. // These features are missing now, but will likely be added:
  21. // - There is no way to specify CallOptions.
  22. package logging
  23. import (
  24. "bytes"
  25. "context"
  26. "encoding/json"
  27. "errors"
  28. "fmt"
  29. "log"
  30. "net/http"
  31. "regexp"
  32. "strconv"
  33. "strings"
  34. "sync"
  35. "time"
  36. "unicode/utf8"
  37. "cloud.google.com/go/compute/metadata"
  38. "cloud.google.com/go/internal/version"
  39. vkit "cloud.google.com/go/logging/apiv2"
  40. "cloud.google.com/go/logging/internal"
  41. "github.com/golang/protobuf/proto"
  42. "github.com/golang/protobuf/ptypes"
  43. structpb "github.com/golang/protobuf/ptypes/struct"
  44. tspb "github.com/golang/protobuf/ptypes/timestamp"
  45. "google.golang.org/api/option"
  46. "google.golang.org/api/support/bundler"
  47. mrpb "google.golang.org/genproto/googleapis/api/monitoredres"
  48. logtypepb "google.golang.org/genproto/googleapis/logging/type"
  49. logpb "google.golang.org/genproto/googleapis/logging/v2"
  50. )
  51. const (
  52. // ReadScope is the scope for reading from the logging service.
  53. ReadScope = "https://www.googleapis.com/auth/logging.read"
  54. // WriteScope is the scope for writing to the logging service.
  55. WriteScope = "https://www.googleapis.com/auth/logging.write"
  56. // AdminScope is the scope for administrative actions on the logging service.
  57. AdminScope = "https://www.googleapis.com/auth/logging.admin"
  58. )
  59. const (
  60. // defaultErrorCapacity is the capacity of the channel used to deliver
  61. // errors to the OnError function.
  62. defaultErrorCapacity = 10
  63. // DefaultDelayThreshold is the default value for the DelayThreshold LoggerOption.
  64. DefaultDelayThreshold = time.Second
  65. // DefaultEntryCountThreshold is the default value for the EntryCountThreshold LoggerOption.
  66. DefaultEntryCountThreshold = 1000
  67. // DefaultEntryByteThreshold is the default value for the EntryByteThreshold LoggerOption.
  68. DefaultEntryByteThreshold = 1 << 20 // 1MiB
  69. // DefaultBufferedByteLimit is the default value for the BufferedByteLimit LoggerOption.
  70. DefaultBufferedByteLimit = 1 << 30 // 1GiB
  71. // defaultWriteTimeout is the timeout for the underlying write API calls. As
  72. // write API calls are not idempotent, they are not retried on timeout. This
  73. // timeout is to allow clients to degrade gracefully if underlying logging
  74. // service is temporarily impaired for some reason.
  75. defaultWriteTimeout = 10 * time.Minute
  76. )
  77. // For testing:
  78. var now = time.Now
  79. // ErrOverflow signals that the number of buffered entries for a Logger
  80. // exceeds its BufferLimit.
  81. var ErrOverflow = bundler.ErrOverflow
  82. // ErrOversizedEntry signals that an entry's size exceeds the maximum number of
  83. // bytes that will be sent in a single call to the logging service.
  84. var ErrOversizedEntry = bundler.ErrOversizedItem
  85. // Client is a Logging client. A Client is associated with a single Cloud project.
  86. type Client struct {
  87. client *vkit.Client // client for the logging service
  88. parent string // e.g. "projects/proj-id"
  89. errc chan error // should be buffered to minimize dropped errors
  90. donec chan struct{} // closed on Client.Close to close Logger bundlers
  91. loggers sync.WaitGroup // so we can wait for loggers to close
  92. closed bool
  93. mu sync.Mutex
  94. nErrs int // number of errors we saw
  95. lastErr error // last error we saw
  96. // OnError is called when an error occurs in a call to Log or Flush. The
  97. // error may be due to an invalid Entry, an overflow because BufferLimit
  98. // was reached (in which case the error will be ErrOverflow) or an error
  99. // communicating with the logging service. OnError is called with errors
  100. // from all Loggers. It is never called concurrently. OnError is expected
  101. // to return quickly; if errors occur while OnError is running, some may
  102. // not be reported. The default behavior is to call log.Printf.
  103. //
  104. // This field should be set only once, before any method of Client is called.
  105. OnError func(err error)
  106. }
  107. // NewClient returns a new logging client associated with the provided parent.
  108. // A parent can take any of the following forms:
  109. // projects/PROJECT_ID
  110. // folders/FOLDER_ID
  111. // billingAccounts/ACCOUNT_ID
  112. // organizations/ORG_ID
  113. // for backwards compatibility, a string with no '/' is also allowed and is interpreted
  114. // as a project ID.
  115. //
  116. // By default NewClient uses WriteScope. To use a different scope, call
  117. // NewClient using a WithScopes option (see https://godoc.org/google.golang.org/api/option#WithScopes).
  118. func NewClient(ctx context.Context, parent string, opts ...option.ClientOption) (*Client, error) {
  119. if !strings.ContainsRune(parent, '/') {
  120. parent = "projects/" + parent
  121. }
  122. opts = append([]option.ClientOption{
  123. option.WithEndpoint(internal.ProdAddr),
  124. option.WithScopes(WriteScope),
  125. }, opts...)
  126. c, err := vkit.NewClient(ctx, opts...)
  127. if err != nil {
  128. return nil, err
  129. }
  130. c.SetGoogleClientInfo("gccl", version.Repo)
  131. client := &Client{
  132. client: c,
  133. parent: parent,
  134. errc: make(chan error, defaultErrorCapacity), // create a small buffer for errors
  135. donec: make(chan struct{}),
  136. OnError: func(e error) { log.Printf("logging client: %v", e) },
  137. }
  138. // Call the user's function synchronously, to make life easier for them.
  139. go func() {
  140. for err := range client.errc {
  141. // This reference to OnError is memory-safe if the user sets OnError before
  142. // calling any client methods. The reference happens before the first read from
  143. // client.errc, which happens before the first write to client.errc, which
  144. // happens before any call, which happens before the user sets OnError.
  145. if fn := client.OnError; fn != nil {
  146. fn(err)
  147. } else {
  148. log.Printf("logging (parent %q): %v", parent, err)
  149. }
  150. }
  151. }()
  152. return client, nil
  153. }
  154. var unixZeroTimestamp *tspb.Timestamp
  155. func init() {
  156. var err error
  157. unixZeroTimestamp, err = ptypes.TimestampProto(time.Unix(0, 0))
  158. if err != nil {
  159. panic(err)
  160. }
  161. }
  162. // Ping reports whether the client's connection to the logging service and the
  163. // authentication configuration are valid. To accomplish this, Ping writes a
  164. // log entry "ping" to a log named "ping".
  165. func (c *Client) Ping(ctx context.Context) error {
  166. ent := &logpb.LogEntry{
  167. Payload: &logpb.LogEntry_TextPayload{TextPayload: "ping"},
  168. Timestamp: unixZeroTimestamp, // Identical timestamps and insert IDs are both
  169. InsertId: "ping", // necessary for the service to dedup these entries.
  170. }
  171. _, err := c.client.WriteLogEntries(ctx, &logpb.WriteLogEntriesRequest{
  172. LogName: internal.LogPath(c.parent, "ping"),
  173. Resource: monitoredResource(c.parent),
  174. Entries: []*logpb.LogEntry{ent},
  175. })
  176. return err
  177. }
  178. // error puts the error on the client's error channel
  179. // without blocking, and records summary error info.
  180. func (c *Client) error(err error) {
  181. select {
  182. case c.errc <- err:
  183. default:
  184. }
  185. c.mu.Lock()
  186. c.lastErr = err
  187. c.nErrs++
  188. c.mu.Unlock()
  189. }
  190. func (c *Client) extractErrorInfo() error {
  191. var err error
  192. c.mu.Lock()
  193. if c.lastErr != nil {
  194. err = fmt.Errorf("saw %d errors; last: %v", c.nErrs, c.lastErr)
  195. c.nErrs = 0
  196. c.lastErr = nil
  197. }
  198. c.mu.Unlock()
  199. return err
  200. }
  201. // A Logger is used to write log messages to a single log. It can be configured
  202. // with a log ID, common monitored resource, and a set of common labels.
  203. type Logger struct {
  204. client *Client
  205. logName string // "projects/{projectID}/logs/{logID}"
  206. stdLoggers map[Severity]*log.Logger
  207. bundler *bundler.Bundler
  208. // Options
  209. commonResource *mrpb.MonitoredResource
  210. commonLabels map[string]string
  211. ctxFunc func() (context.Context, func())
  212. }
  213. // A LoggerOption is a configuration option for a Logger.
  214. type LoggerOption interface {
  215. set(*Logger)
  216. }
  217. // CommonResource sets the monitored resource associated with all log entries
  218. // written from a Logger. If not provided, the resource is automatically
  219. // detected based on the running environment. This value can be overridden
  220. // per-entry by setting an Entry's Resource field.
  221. func CommonResource(r *mrpb.MonitoredResource) LoggerOption { return commonResource{r} }
  222. type commonResource struct{ *mrpb.MonitoredResource }
  223. func (r commonResource) set(l *Logger) { l.commonResource = r.MonitoredResource }
  224. var detectedResource struct {
  225. pb *mrpb.MonitoredResource
  226. once sync.Once
  227. }
  228. func detectResource() *mrpb.MonitoredResource {
  229. detectedResource.once.Do(func() {
  230. if !metadata.OnGCE() {
  231. return
  232. }
  233. projectID, err := metadata.ProjectID()
  234. if err != nil {
  235. return
  236. }
  237. id, err := metadata.InstanceID()
  238. if err != nil {
  239. return
  240. }
  241. zone, err := metadata.Zone()
  242. if err != nil {
  243. return
  244. }
  245. name, err := metadata.InstanceName()
  246. if err != nil {
  247. return
  248. }
  249. detectedResource.pb = &mrpb.MonitoredResource{
  250. Type: "gce_instance",
  251. Labels: map[string]string{
  252. "project_id": projectID,
  253. "instance_id": id,
  254. "instance_name": name,
  255. "zone": zone,
  256. },
  257. }
  258. })
  259. return detectedResource.pb
  260. }
  261. var resourceInfo = map[string]struct{ rtype, label string }{
  262. "organizations": {"organization", "organization_id"},
  263. "folders": {"folder", "folder_id"},
  264. "projects": {"project", "project_id"},
  265. "billingAccounts": {"billing_account", "account_id"},
  266. }
  267. func monitoredResource(parent string) *mrpb.MonitoredResource {
  268. parts := strings.SplitN(parent, "/", 2)
  269. if len(parts) != 2 {
  270. return globalResource(parent)
  271. }
  272. info, ok := resourceInfo[parts[0]]
  273. if !ok {
  274. return globalResource(parts[1])
  275. }
  276. return &mrpb.MonitoredResource{
  277. Type: info.rtype,
  278. Labels: map[string]string{info.label: parts[1]},
  279. }
  280. }
  281. func globalResource(projectID string) *mrpb.MonitoredResource {
  282. return &mrpb.MonitoredResource{
  283. Type: "global",
  284. Labels: map[string]string{
  285. "project_id": projectID,
  286. },
  287. }
  288. }
  289. // CommonLabels are labels that apply to all log entries written from a Logger,
  290. // so that you don't have to repeat them in each log entry's Labels field. If
  291. // any of the log entries contains a (key, value) with the same key that is in
  292. // CommonLabels, then the entry's (key, value) overrides the one in
  293. // CommonLabels.
  294. func CommonLabels(m map[string]string) LoggerOption { return commonLabels(m) }
  295. type commonLabels map[string]string
  296. func (c commonLabels) set(l *Logger) { l.commonLabels = c }
  297. // ConcurrentWriteLimit determines how many goroutines will send log entries to the
  298. // underlying service. The default is 1. Set ConcurrentWriteLimit to a higher value to
  299. // increase throughput.
  300. func ConcurrentWriteLimit(n int) LoggerOption { return concurrentWriteLimit(n) }
  301. type concurrentWriteLimit int
  302. func (c concurrentWriteLimit) set(l *Logger) { l.bundler.HandlerLimit = int(c) }
  303. // DelayThreshold is the maximum amount of time that an entry should remain
  304. // buffered in memory before a call to the logging service is triggered. Larger
  305. // values of DelayThreshold will generally result in fewer calls to the logging
  306. // service, while increasing the risk that log entries will be lost if the
  307. // process crashes.
  308. // The default is DefaultDelayThreshold.
  309. func DelayThreshold(d time.Duration) LoggerOption { return delayThreshold(d) }
  310. type delayThreshold time.Duration
  311. func (d delayThreshold) set(l *Logger) { l.bundler.DelayThreshold = time.Duration(d) }
  312. // EntryCountThreshold is the maximum number of entries that will be buffered
  313. // in memory before a call to the logging service is triggered. Larger values
  314. // will generally result in fewer calls to the logging service, while
  315. // increasing both memory consumption and the risk that log entries will be
  316. // lost if the process crashes.
  317. // The default is DefaultEntryCountThreshold.
  318. func EntryCountThreshold(n int) LoggerOption { return entryCountThreshold(n) }
  319. type entryCountThreshold int
  320. func (e entryCountThreshold) set(l *Logger) { l.bundler.BundleCountThreshold = int(e) }
  321. // EntryByteThreshold is the maximum number of bytes of entries that will be
  322. // buffered in memory before a call to the logging service is triggered. See
  323. // EntryCountThreshold for a discussion of the tradeoffs involved in setting
  324. // this option.
  325. // The default is DefaultEntryByteThreshold.
  326. func EntryByteThreshold(n int) LoggerOption { return entryByteThreshold(n) }
  327. type entryByteThreshold int
  328. func (e entryByteThreshold) set(l *Logger) { l.bundler.BundleByteThreshold = int(e) }
  329. // EntryByteLimit is the maximum number of bytes of entries that will be sent
  330. // in a single call to the logging service. ErrOversizedEntry is returned if an
  331. // entry exceeds EntryByteLimit. This option limits the size of a single RPC
  332. // payload, to account for network or service issues with large RPCs. If
  333. // EntryByteLimit is smaller than EntryByteThreshold, the latter has no effect.
  334. // The default is zero, meaning there is no limit.
  335. func EntryByteLimit(n int) LoggerOption { return entryByteLimit(n) }
  336. type entryByteLimit int
  337. func (e entryByteLimit) set(l *Logger) { l.bundler.BundleByteLimit = int(e) }
  338. // BufferedByteLimit is the maximum number of bytes that the Logger will keep
  339. // in memory before returning ErrOverflow. This option limits the total memory
  340. // consumption of the Logger (but note that each Logger has its own, separate
  341. // limit). It is possible to reach BufferedByteLimit even if it is larger than
  342. // EntryByteThreshold or EntryByteLimit, because calls triggered by the latter
  343. // two options may be enqueued (and hence occupying memory) while new log
  344. // entries are being added.
  345. // The default is DefaultBufferedByteLimit.
  346. func BufferedByteLimit(n int) LoggerOption { return bufferedByteLimit(n) }
  347. type bufferedByteLimit int
  348. func (b bufferedByteLimit) set(l *Logger) { l.bundler.BufferedByteLimit = int(b) }
  349. // ContextFunc is a function that will be called to obtain a context.Context for the
  350. // WriteLogEntries RPC executed in the background for calls to Logger.Log. The
  351. // default is a function that always returns context.Background. The second return
  352. // value of the function is a function to call after the RPC completes.
  353. //
  354. // The function is not used for calls to Logger.LogSync, since the caller can pass
  355. // in the context directly.
  356. //
  357. // This option is EXPERIMENTAL. It may be changed or removed.
  358. func ContextFunc(f func() (ctx context.Context, afterCall func())) LoggerOption {
  359. return contextFunc(f)
  360. }
  361. type contextFunc func() (ctx context.Context, afterCall func())
  362. func (c contextFunc) set(l *Logger) { l.ctxFunc = c }
  363. // Logger returns a Logger that will write entries with the given log ID, such as
  364. // "syslog". A log ID must be less than 512 characters long and can only
  365. // include the following characters: upper and lower case alphanumeric
  366. // characters: [A-Za-z0-9]; and punctuation characters: forward-slash,
  367. // underscore, hyphen, and period.
  368. func (c *Client) Logger(logID string, opts ...LoggerOption) *Logger {
  369. r := detectResource()
  370. if r == nil {
  371. r = monitoredResource(c.parent)
  372. }
  373. l := &Logger{
  374. client: c,
  375. logName: internal.LogPath(c.parent, logID),
  376. commonResource: r,
  377. ctxFunc: func() (context.Context, func()) { return context.Background(), nil },
  378. }
  379. l.bundler = bundler.NewBundler(&logpb.LogEntry{}, func(entries interface{}) {
  380. l.writeLogEntries(entries.([]*logpb.LogEntry))
  381. })
  382. l.bundler.DelayThreshold = DefaultDelayThreshold
  383. l.bundler.BundleCountThreshold = DefaultEntryCountThreshold
  384. l.bundler.BundleByteThreshold = DefaultEntryByteThreshold
  385. l.bundler.BufferedByteLimit = DefaultBufferedByteLimit
  386. for _, opt := range opts {
  387. opt.set(l)
  388. }
  389. l.stdLoggers = map[Severity]*log.Logger{}
  390. for s := range severityName {
  391. l.stdLoggers[s] = log.New(severityWriter{l, s}, "", 0)
  392. }
  393. c.loggers.Add(1)
  394. // Start a goroutine that cleans up the bundler, its channel
  395. // and the writer goroutines when the client is closed.
  396. go func() {
  397. defer c.loggers.Done()
  398. <-c.donec
  399. l.bundler.Flush()
  400. }()
  401. return l
  402. }
  403. type severityWriter struct {
  404. l *Logger
  405. s Severity
  406. }
  407. func (w severityWriter) Write(p []byte) (n int, err error) {
  408. w.l.Log(Entry{
  409. Severity: w.s,
  410. Payload: string(p),
  411. })
  412. return len(p), nil
  413. }
  414. // Close waits for all opened loggers to be flushed and closes the client.
  415. func (c *Client) Close() error {
  416. if c.closed {
  417. return nil
  418. }
  419. close(c.donec) // close Logger bundlers
  420. c.loggers.Wait() // wait for all bundlers to flush and close
  421. // Now there can be no more errors.
  422. close(c.errc) // terminate error goroutine
  423. // Prefer errors arising from logging to the error returned from Close.
  424. err := c.extractErrorInfo()
  425. err2 := c.client.Close()
  426. if err == nil {
  427. err = err2
  428. }
  429. c.closed = true
  430. return err
  431. }
  432. // Severity is the severity of the event described in a log entry. These
  433. // guideline severity levels are ordered, with numerically smaller levels
  434. // treated as less severe than numerically larger levels.
  435. type Severity int
  436. const (
  437. // Default means the log entry has no assigned severity level.
  438. Default = Severity(logtypepb.LogSeverity_DEFAULT)
  439. // Debug means debug or trace information.
  440. Debug = Severity(logtypepb.LogSeverity_DEBUG)
  441. // Info means routine information, such as ongoing status or performance.
  442. Info = Severity(logtypepb.LogSeverity_INFO)
  443. // Notice means normal but significant events, such as start up, shut down, or configuration.
  444. Notice = Severity(logtypepb.LogSeverity_NOTICE)
  445. // Warning means events that might cause problems.
  446. Warning = Severity(logtypepb.LogSeverity_WARNING)
  447. // Error means events that are likely to cause problems.
  448. Error = Severity(logtypepb.LogSeverity_ERROR)
  449. // Critical means events that cause more severe problems or brief outages.
  450. Critical = Severity(logtypepb.LogSeverity_CRITICAL)
  451. // Alert means a person must take an action immediately.
  452. Alert = Severity(logtypepb.LogSeverity_ALERT)
  453. // Emergency means one or more systems are unusable.
  454. Emergency = Severity(logtypepb.LogSeverity_EMERGENCY)
  455. )
  456. var severityName = map[Severity]string{
  457. Default: "Default",
  458. Debug: "Debug",
  459. Info: "Info",
  460. Notice: "Notice",
  461. Warning: "Warning",
  462. Error: "Error",
  463. Critical: "Critical",
  464. Alert: "Alert",
  465. Emergency: "Emergency",
  466. }
  467. // String converts a severity level to a string.
  468. func (v Severity) String() string {
  469. // same as proto.EnumName
  470. s, ok := severityName[v]
  471. if ok {
  472. return s
  473. }
  474. return strconv.Itoa(int(v))
  475. }
  476. // ParseSeverity returns the Severity whose name equals s, ignoring case. It
  477. // returns Default if no Severity matches.
  478. func ParseSeverity(s string) Severity {
  479. sl := strings.ToLower(s)
  480. for sev, name := range severityName {
  481. if strings.ToLower(name) == sl {
  482. return sev
  483. }
  484. }
  485. return Default
  486. }
  487. // Entry is a log entry.
  488. // See https://cloud.google.com/logging/docs/view/logs_index for more about entries.
  489. type Entry struct {
  490. // Timestamp is the time of the entry. If zero, the current time is used.
  491. Timestamp time.Time
  492. // Severity is the entry's severity level.
  493. // The zero value is Default.
  494. Severity Severity
  495. // Payload must be either a string, or something that marshals via the
  496. // encoding/json package to a JSON object (and not any other type of JSON value).
  497. Payload interface{}
  498. // Labels optionally specifies key/value labels for the log entry.
  499. // The Logger.Log method takes ownership of this map. See Logger.CommonLabels
  500. // for more about labels.
  501. Labels map[string]string
  502. // InsertID is a unique ID for the log entry. If you provide this field,
  503. // the logging service considers other log entries in the same log with the
  504. // same ID as duplicates which can be removed. If omitted, the logging
  505. // service will generate a unique ID for this log entry. Note that because
  506. // this client retries RPCs automatically, it is possible (though unlikely)
  507. // that an Entry without an InsertID will be written more than once.
  508. InsertID string
  509. // HTTPRequest optionally specifies metadata about the HTTP request
  510. // associated with this log entry, if applicable. It is optional.
  511. HTTPRequest *HTTPRequest
  512. // Operation optionally provides information about an operation associated
  513. // with the log entry, if applicable.
  514. Operation *logpb.LogEntryOperation
  515. // LogName is the full log name, in the form
  516. // "projects/{ProjectID}/logs/{LogID}". It is set by the client when
  517. // reading entries. It is an error to set it when writing entries.
  518. LogName string
  519. // Resource is the monitored resource associated with the entry.
  520. Resource *mrpb.MonitoredResource
  521. // Trace is the resource name of the trace associated with the log entry,
  522. // if any. If it contains a relative resource name, the name is assumed to
  523. // be relative to //tracing.googleapis.com.
  524. Trace string
  525. // ID of the span within the trace associated with the log entry.
  526. // The ID is a 16-character hexadecimal encoding of an 8-byte array.
  527. SpanID string
  528. // If set, symbolizes that this request was sampled.
  529. TraceSampled bool
  530. // Optional. Source code location information associated with the log entry,
  531. // if any.
  532. SourceLocation *logpb.LogEntrySourceLocation
  533. }
  534. // HTTPRequest contains an http.Request as well as additional
  535. // information about the request and its response.
  536. type HTTPRequest struct {
  537. // Request is the http.Request passed to the handler.
  538. Request *http.Request
  539. // RequestSize is the size of the HTTP request message in bytes, including
  540. // the request headers and the request body.
  541. RequestSize int64
  542. // Status is the response code indicating the status of the response.
  543. // Examples: 200, 404.
  544. Status int
  545. // ResponseSize is the size of the HTTP response message sent back to the client, in bytes,
  546. // including the response headers and the response body.
  547. ResponseSize int64
  548. // Latency is the request processing latency on the server, from the time the request was
  549. // received until the response was sent.
  550. Latency time.Duration
  551. // LocalIP is the IP address (IPv4 or IPv6) of the origin server that the request
  552. // was sent to.
  553. LocalIP string
  554. // RemoteIP is the IP address (IPv4 or IPv6) of the client that issued the
  555. // HTTP request. Examples: "192.168.1.1", "FE80::0202:B3FF:FE1E:8329".
  556. RemoteIP string
  557. // CacheHit reports whether an entity was served from cache (with or without
  558. // validation).
  559. CacheHit bool
  560. // CacheValidatedWithOriginServer reports whether the response was
  561. // validated with the origin server before being served from cache. This
  562. // field is only meaningful if CacheHit is true.
  563. CacheValidatedWithOriginServer bool
  564. }
  565. func fromHTTPRequest(r *HTTPRequest) *logtypepb.HttpRequest {
  566. if r == nil {
  567. return nil
  568. }
  569. if r.Request == nil {
  570. panic("HTTPRequest must have a non-nil Request")
  571. }
  572. u := *r.Request.URL
  573. u.Fragment = ""
  574. pb := &logtypepb.HttpRequest{
  575. RequestMethod: r.Request.Method,
  576. RequestUrl: fixUTF8(u.String()),
  577. RequestSize: r.RequestSize,
  578. Status: int32(r.Status),
  579. ResponseSize: r.ResponseSize,
  580. UserAgent: r.Request.UserAgent(),
  581. ServerIp: r.LocalIP,
  582. RemoteIp: r.RemoteIP, // TODO(jba): attempt to parse http.Request.RemoteAddr?
  583. Referer: r.Request.Referer(),
  584. CacheHit: r.CacheHit,
  585. CacheValidatedWithOriginServer: r.CacheValidatedWithOriginServer,
  586. }
  587. if r.Latency != 0 {
  588. pb.Latency = ptypes.DurationProto(r.Latency)
  589. }
  590. return pb
  591. }
  592. // fixUTF8 is a helper that fixes an invalid UTF-8 string by replacing
  593. // invalid UTF-8 runes with the Unicode replacement character (U+FFFD).
  594. // See Issue https://github.com/googleapis/google-cloud-go/issues/1383.
  595. func fixUTF8(s string) string {
  596. if utf8.ValidString(s) {
  597. return s
  598. }
  599. // Otherwise time to build the sequence.
  600. buf := new(bytes.Buffer)
  601. buf.Grow(len(s))
  602. for _, r := range s {
  603. if utf8.ValidRune(r) {
  604. buf.WriteRune(r)
  605. } else {
  606. buf.WriteRune('\uFFFD')
  607. }
  608. }
  609. return buf.String()
  610. }
  611. // toProtoStruct converts v, which must marshal into a JSON object,
  612. // into a Google Struct proto.
  613. func toProtoStruct(v interface{}) (*structpb.Struct, error) {
  614. // Fast path: if v is already a *structpb.Struct, nothing to do.
  615. if s, ok := v.(*structpb.Struct); ok {
  616. return s, nil
  617. }
  618. // v is a Go value that supports JSON marshalling. We want a Struct
  619. // protobuf. Some day we may have a more direct way to get there, but right
  620. // now the only way is to marshal the Go value to JSON, unmarshal into a
  621. // map, and then build the Struct proto from the map.
  622. var jb []byte
  623. var err error
  624. if raw, ok := v.(json.RawMessage); ok { // needed for Go 1.7 and below
  625. jb = []byte(raw)
  626. } else {
  627. jb, err = json.Marshal(v)
  628. if err != nil {
  629. return nil, fmt.Errorf("logging: json.Marshal: %v", err)
  630. }
  631. }
  632. var m map[string]interface{}
  633. err = json.Unmarshal(jb, &m)
  634. if err != nil {
  635. return nil, fmt.Errorf("logging: json.Unmarshal: %v", err)
  636. }
  637. return jsonMapToProtoStruct(m), nil
  638. }
  639. func jsonMapToProtoStruct(m map[string]interface{}) *structpb.Struct {
  640. fields := map[string]*structpb.Value{}
  641. for k, v := range m {
  642. fields[k] = jsonValueToStructValue(v)
  643. }
  644. return &structpb.Struct{Fields: fields}
  645. }
  646. func jsonValueToStructValue(v interface{}) *structpb.Value {
  647. switch x := v.(type) {
  648. case bool:
  649. return &structpb.Value{Kind: &structpb.Value_BoolValue{BoolValue: x}}
  650. case float64:
  651. return &structpb.Value{Kind: &structpb.Value_NumberValue{NumberValue: x}}
  652. case string:
  653. return &structpb.Value{Kind: &structpb.Value_StringValue{StringValue: x}}
  654. case nil:
  655. return &structpb.Value{Kind: &structpb.Value_NullValue{}}
  656. case map[string]interface{}:
  657. return &structpb.Value{Kind: &structpb.Value_StructValue{StructValue: jsonMapToProtoStruct(x)}}
  658. case []interface{}:
  659. var vals []*structpb.Value
  660. for _, e := range x {
  661. vals = append(vals, jsonValueToStructValue(e))
  662. }
  663. return &structpb.Value{Kind: &structpb.Value_ListValue{ListValue: &structpb.ListValue{Values: vals}}}
  664. default:
  665. panic(fmt.Sprintf("bad type %T for JSON value", v))
  666. }
  667. }
  668. // LogSync logs the Entry synchronously without any buffering. Because LogSync is slow
  669. // and will block, it is intended primarily for debugging or critical errors.
  670. // Prefer Log for most uses.
  671. // TODO(jba): come up with a better name (LogNow?) or eliminate.
  672. func (l *Logger) LogSync(ctx context.Context, e Entry) error {
  673. ent, err := l.toLogEntry(e)
  674. if err != nil {
  675. return err
  676. }
  677. _, err = l.client.client.WriteLogEntries(ctx, &logpb.WriteLogEntriesRequest{
  678. LogName: l.logName,
  679. Resource: l.commonResource,
  680. Labels: l.commonLabels,
  681. Entries: []*logpb.LogEntry{ent},
  682. })
  683. return err
  684. }
  685. // Log buffers the Entry for output to the logging service. It never blocks.
  686. func (l *Logger) Log(e Entry) {
  687. ent, err := l.toLogEntry(e)
  688. if err != nil {
  689. l.client.error(err)
  690. return
  691. }
  692. if err := l.bundler.Add(ent, proto.Size(ent)); err != nil {
  693. l.client.error(err)
  694. }
  695. }
  696. // Flush blocks until all currently buffered log entries are sent.
  697. //
  698. // If any errors occurred since the last call to Flush from any Logger, or the
  699. // creation of the client if this is the first call, then Flush returns a non-nil
  700. // error with summary information about the errors. This information is unlikely to
  701. // be actionable. For more accurate error reporting, set Client.OnError.
  702. func (l *Logger) Flush() error {
  703. l.bundler.Flush()
  704. return l.client.extractErrorInfo()
  705. }
  706. func (l *Logger) writeLogEntries(entries []*logpb.LogEntry) {
  707. req := &logpb.WriteLogEntriesRequest{
  708. LogName: l.logName,
  709. Resource: l.commonResource,
  710. Labels: l.commonLabels,
  711. Entries: entries,
  712. }
  713. ctx, afterCall := l.ctxFunc()
  714. ctx, cancel := context.WithTimeout(ctx, defaultWriteTimeout)
  715. defer cancel()
  716. _, err := l.client.client.WriteLogEntries(ctx, req)
  717. if err != nil {
  718. l.client.error(err)
  719. }
  720. if afterCall != nil {
  721. afterCall()
  722. }
  723. }
  724. // StandardLogger returns a *log.Logger for the provided severity.
  725. //
  726. // This method is cheap. A single log.Logger is pre-allocated for each
  727. // severity level in each Logger. Callers may mutate the returned log.Logger
  728. // (for example by calling SetFlags or SetPrefix).
  729. func (l *Logger) StandardLogger(s Severity) *log.Logger { return l.stdLoggers[s] }
  730. var reCloudTraceContext = regexp.MustCompile(`([a-f\d]+)/([a-f\d]+);o=(\d)`)
  731. func deconstructXCloudTraceContext(s string) (traceID, spanID string, traceSampled bool) {
  732. // As per the format described at https://cloud.google.com/trace/docs/troubleshooting#force-trace
  733. // "X-Cloud-Trace-Context: TRACE_ID/SPAN_ID;o=TRACE_TRUE"
  734. // for example:
  735. // "X-Cloud-Trace-Context: 105445aa7843bc8bf206b120001000/0;o=1"
  736. //
  737. // We expect:
  738. // * traceID: "105445aa7843bc8bf206b120001000"
  739. // * spanID: ""
  740. // * traceSampled: true
  741. matches := reCloudTraceContext.FindAllStringSubmatch(s, -1)
  742. if len(matches) != 1 {
  743. return
  744. }
  745. sub := matches[0]
  746. if len(sub) != 4 {
  747. return
  748. }
  749. traceID, spanID = sub[1], sub[2]
  750. if spanID == "0" {
  751. spanID = ""
  752. }
  753. traceSampled = sub[3] == "1"
  754. return
  755. }
  756. func (l *Logger) toLogEntry(e Entry) (*logpb.LogEntry, error) {
  757. if e.LogName != "" {
  758. return nil, errors.New("logging: Entry.LogName should be not be set when writing")
  759. }
  760. t := e.Timestamp
  761. if t.IsZero() {
  762. t = now()
  763. }
  764. ts, err := ptypes.TimestampProto(t)
  765. if err != nil {
  766. return nil, err
  767. }
  768. if e.Trace == "" && e.HTTPRequest != nil && e.HTTPRequest.Request != nil {
  769. traceHeader := e.HTTPRequest.Request.Header.Get("X-Cloud-Trace-Context")
  770. if traceHeader != "" {
  771. // Set to a relative resource name, as described at
  772. // https://cloud.google.com/appengine/docs/flexible/go/writing-application-logs.
  773. traceID, spanID, traceSampled := deconstructXCloudTraceContext(traceHeader)
  774. if traceID != "" {
  775. e.Trace = fmt.Sprintf("%s/traces/%s", l.client.parent, traceID)
  776. }
  777. if e.SpanID == "" {
  778. e.SpanID = spanID
  779. }
  780. // If we previously hadn't set TraceSampled, let's retrieve it
  781. // from the HTTP request's header, as per:
  782. // https://cloud.google.com/trace/docs/troubleshooting#force-trace
  783. e.TraceSampled = e.TraceSampled || traceSampled
  784. }
  785. }
  786. ent := &logpb.LogEntry{
  787. Timestamp: ts,
  788. Severity: logtypepb.LogSeverity(e.Severity),
  789. InsertId: e.InsertID,
  790. HttpRequest: fromHTTPRequest(e.HTTPRequest),
  791. Operation: e.Operation,
  792. Labels: e.Labels,
  793. Trace: e.Trace,
  794. SpanId: e.SpanID,
  795. Resource: e.Resource,
  796. SourceLocation: e.SourceLocation,
  797. TraceSampled: e.TraceSampled,
  798. }
  799. switch p := e.Payload.(type) {
  800. case string:
  801. ent.Payload = &logpb.LogEntry_TextPayload{TextPayload: p}
  802. default:
  803. s, err := toProtoStruct(p)
  804. if err != nil {
  805. return nil, err
  806. }
  807. ent.Payload = &logpb.LogEntry_JsonPayload{JsonPayload: s}
  808. }
  809. return ent, nil
  810. }