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