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// UnmarshalJSON turns a string representation of severity into the type 570// Severity. 571func (v *Severity) UnmarshalJSON(data []byte) error { 572 var s string 573 if err := json.Unmarshal(data, &s); err != nil { 574 return err 575 } 576 *v = ParseSeverity(s) 577 return nil 578} 579 580// ParseSeverity returns the Severity whose name equals s, ignoring case. It 581// returns Default if no Severity matches. 582func ParseSeverity(s string) Severity { 583 sl := strings.ToLower(s) 584 for sev, name := range severityName { 585 if strings.ToLower(name) == sl { 586 return sev 587 } 588 } 589 return Default 590} 591 592// Entry is a log entry. 593// See https://cloud.google.com/logging/docs/view/logs_index for more about entries. 594type Entry struct { 595 // Timestamp is the time of the entry. If zero, the current time is used. 596 Timestamp time.Time 597 598 // Severity is the entry's severity level. 599 // The zero value is Default. 600 Severity Severity 601 602 // Payload must be either a string, or something that marshals via the 603 // encoding/json package to a JSON object (and not any other type of JSON value). 604 Payload interface{} 605 606 // Labels optionally specifies key/value labels for the log entry. 607 // The Logger.Log method takes ownership of this map. See Logger.CommonLabels 608 // for more about labels. 609 Labels map[string]string 610 611 // InsertID is a unique ID for the log entry. If you provide this field, 612 // the logging service considers other log entries in the same log with the 613 // same ID as duplicates which can be removed. If omitted, the logging 614 // service will generate a unique ID for this log entry. Note that because 615 // this client retries RPCs automatically, it is possible (though unlikely) 616 // that an Entry without an InsertID will be written more than once. 617 InsertID string 618 619 // HTTPRequest optionally specifies metadata about the HTTP request 620 // associated with this log entry, if applicable. It is optional. 621 HTTPRequest *HTTPRequest 622 623 // Operation optionally provides information about an operation associated 624 // with the log entry, if applicable. 625 Operation *logpb.LogEntryOperation 626 627 // LogName is the full log name, in the form 628 // "projects/{ProjectID}/logs/{LogID}". It is set by the client when 629 // reading entries. It is an error to set it when writing entries. 630 LogName string 631 632 // Resource is the monitored resource associated with the entry. 633 Resource *mrpb.MonitoredResource 634 635 // Trace is the resource name of the trace associated with the log entry, 636 // if any. If it contains a relative resource name, the name is assumed to 637 // be relative to //tracing.googleapis.com. 638 Trace string 639 640 // ID of the span within the trace associated with the log entry. 641 // The ID is a 16-character hexadecimal encoding of an 8-byte array. 642 SpanID string 643 644 // If set, symbolizes that this request was sampled. 645 TraceSampled bool 646 647 // Optional. Source code location information associated with the log entry, 648 // if any. 649 SourceLocation *logpb.LogEntrySourceLocation 650} 651 652// HTTPRequest contains an http.Request as well as additional 653// information about the request and its response. 654type HTTPRequest struct { 655 // Request is the http.Request passed to the handler. 656 Request *http.Request 657 658 // RequestSize is the size of the HTTP request message in bytes, including 659 // the request headers and the request body. 660 RequestSize int64 661 662 // Status is the response code indicating the status of the response. 663 // Examples: 200, 404. 664 Status int 665 666 // ResponseSize is the size of the HTTP response message sent back to the client, in bytes, 667 // including the response headers and the response body. 668 ResponseSize int64 669 670 // Latency is the request processing latency on the server, from the time the request was 671 // received until the response was sent. 672 Latency time.Duration 673 674 // LocalIP is the IP address (IPv4 or IPv6) of the origin server that the request 675 // was sent to. 676 LocalIP string 677 678 // RemoteIP is the IP address (IPv4 or IPv6) of the client that issued the 679 // HTTP request. Examples: "192.168.1.1", "FE80::0202:B3FF:FE1E:8329". 680 RemoteIP string 681 682 // CacheHit reports whether an entity was served from cache (with or without 683 // validation). 684 CacheHit bool 685 686 // CacheValidatedWithOriginServer reports whether the response was 687 // validated with the origin server before being served from cache. This 688 // field is only meaningful if CacheHit is true. 689 CacheValidatedWithOriginServer bool 690} 691 692func fromHTTPRequest(r *HTTPRequest) *logtypepb.HttpRequest { 693 if r == nil { 694 return nil 695 } 696 if r.Request == nil { 697 panic("HTTPRequest must have a non-nil Request") 698 } 699 u := *r.Request.URL 700 u.Fragment = "" 701 pb := &logtypepb.HttpRequest{ 702 RequestMethod: r.Request.Method, 703 RequestUrl: fixUTF8(u.String()), 704 RequestSize: r.RequestSize, 705 Status: int32(r.Status), 706 ResponseSize: r.ResponseSize, 707 UserAgent: r.Request.UserAgent(), 708 ServerIp: r.LocalIP, 709 RemoteIp: r.RemoteIP, // TODO(jba): attempt to parse http.Request.RemoteAddr? 710 Referer: r.Request.Referer(), 711 CacheHit: r.CacheHit, 712 CacheValidatedWithOriginServer: r.CacheValidatedWithOriginServer, 713 } 714 if r.Latency != 0 { 715 pb.Latency = ptypes.DurationProto(r.Latency) 716 } 717 return pb 718} 719 720// fixUTF8 is a helper that fixes an invalid UTF-8 string by replacing 721// invalid UTF-8 runes with the Unicode replacement character (U+FFFD). 722// See Issue https://github.com/googleapis/google-cloud-go/issues/1383. 723func fixUTF8(s string) string { 724 if utf8.ValidString(s) { 725 return s 726 } 727 728 // Otherwise time to build the sequence. 729 buf := new(bytes.Buffer) 730 buf.Grow(len(s)) 731 for _, r := range s { 732 if utf8.ValidRune(r) { 733 buf.WriteRune(r) 734 } else { 735 buf.WriteRune('\uFFFD') 736 } 737 } 738 return buf.String() 739} 740 741// toProtoStruct converts v, which must marshal into a JSON object, 742// into a Google Struct proto. 743func toProtoStruct(v interface{}) (*structpb.Struct, error) { 744 // Fast path: if v is already a *structpb.Struct, nothing to do. 745 if s, ok := v.(*structpb.Struct); ok { 746 return s, nil 747 } 748 // v is a Go value that supports JSON marshalling. We want a Struct 749 // protobuf. Some day we may have a more direct way to get there, but right 750 // now the only way is to marshal the Go value to JSON, unmarshal into a 751 // map, and then build the Struct proto from the map. 752 var jb []byte 753 var err error 754 if raw, ok := v.(json.RawMessage); ok { // needed for Go 1.7 and below 755 jb = []byte(raw) 756 } else { 757 jb, err = json.Marshal(v) 758 if err != nil { 759 return nil, fmt.Errorf("logging: json.Marshal: %v", err) 760 } 761 } 762 var m map[string]interface{} 763 err = json.Unmarshal(jb, &m) 764 if err != nil { 765 return nil, fmt.Errorf("logging: json.Unmarshal: %v", err) 766 } 767 return jsonMapToProtoStruct(m), nil 768} 769 770func jsonMapToProtoStruct(m map[string]interface{}) *structpb.Struct { 771 fields := map[string]*structpb.Value{} 772 for k, v := range m { 773 fields[k] = jsonValueToStructValue(v) 774 } 775 return &structpb.Struct{Fields: fields} 776} 777 778func jsonValueToStructValue(v interface{}) *structpb.Value { 779 switch x := v.(type) { 780 case bool: 781 return &structpb.Value{Kind: &structpb.Value_BoolValue{BoolValue: x}} 782 case float64: 783 return &structpb.Value{Kind: &structpb.Value_NumberValue{NumberValue: x}} 784 case string: 785 return &structpb.Value{Kind: &structpb.Value_StringValue{StringValue: x}} 786 case nil: 787 return &structpb.Value{Kind: &structpb.Value_NullValue{}} 788 case map[string]interface{}: 789 return &structpb.Value{Kind: &structpb.Value_StructValue{StructValue: jsonMapToProtoStruct(x)}} 790 case []interface{}: 791 var vals []*structpb.Value 792 for _, e := range x { 793 vals = append(vals, jsonValueToStructValue(e)) 794 } 795 return &structpb.Value{Kind: &structpb.Value_ListValue{ListValue: &structpb.ListValue{Values: vals}}} 796 default: 797 panic(fmt.Sprintf("bad type %T for JSON value", v)) 798 } 799} 800 801// LogSync logs the Entry synchronously without any buffering. Because LogSync is slow 802// and will block, it is intended primarily for debugging or critical errors. 803// Prefer Log for most uses. 804func (l *Logger) LogSync(ctx context.Context, e Entry) error { 805 ent, err := l.toLogEntry(e) 806 if err != nil { 807 return err 808 } 809 _, err = l.client.client.WriteLogEntries(ctx, &logpb.WriteLogEntriesRequest{ 810 LogName: l.logName, 811 Resource: l.commonResource, 812 Labels: l.commonLabels, 813 Entries: []*logpb.LogEntry{ent}, 814 }) 815 return err 816} 817 818// Log buffers the Entry for output to the logging service. It never blocks. 819func (l *Logger) Log(e Entry) { 820 ent, err := l.toLogEntry(e) 821 if err != nil { 822 l.client.error(err) 823 return 824 } 825 if err := l.bundler.Add(ent, proto.Size(ent)); err != nil { 826 l.client.error(err) 827 } 828} 829 830// Flush blocks until all currently buffered log entries are sent. 831// 832// If any errors occurred since the last call to Flush from any Logger, or the 833// creation of the client if this is the first call, then Flush returns a non-nil 834// error with summary information about the errors. This information is unlikely to 835// be actionable. For more accurate error reporting, set Client.OnError. 836func (l *Logger) Flush() error { 837 l.bundler.Flush() 838 return l.client.extractErrorInfo() 839} 840 841func (l *Logger) writeLogEntries(entries []*logpb.LogEntry) { 842 req := &logpb.WriteLogEntriesRequest{ 843 LogName: l.logName, 844 Resource: l.commonResource, 845 Labels: l.commonLabels, 846 Entries: entries, 847 } 848 ctx, afterCall := l.ctxFunc() 849 ctx, cancel := context.WithTimeout(ctx, defaultWriteTimeout) 850 defer cancel() 851 _, err := l.client.client.WriteLogEntries(ctx, req) 852 if err != nil { 853 l.client.error(err) 854 } 855 if afterCall != nil { 856 afterCall() 857 } 858} 859 860// StandardLogger returns a *log.Logger for the provided severity. 861// 862// This method is cheap. A single log.Logger is pre-allocated for each 863// severity level in each Logger. Callers may mutate the returned log.Logger 864// (for example by calling SetFlags or SetPrefix). 865func (l *Logger) StandardLogger(s Severity) *log.Logger { return l.stdLoggers[s] } 866 867var reCloudTraceContext = regexp.MustCompile(`([a-f\d]+)/([a-f\d]+);o=(\d)`) 868 869func deconstructXCloudTraceContext(s string) (traceID, spanID string, traceSampled bool) { 870 // As per the format described at https://cloud.google.com/trace/docs/troubleshooting#force-trace 871 // "X-Cloud-Trace-Context: TRACE_ID/SPAN_ID;o=TRACE_TRUE" 872 // for example: 873 // "X-Cloud-Trace-Context: 105445aa7843bc8bf206b120001000/0;o=1" 874 // 875 // We expect: 876 // * traceID: "105445aa7843bc8bf206b120001000" 877 // * spanID: "" 878 // * traceSampled: true 879 matches := reCloudTraceContext.FindAllStringSubmatch(s, -1) 880 if len(matches) != 1 { 881 return 882 } 883 884 sub := matches[0] 885 if len(sub) != 4 { 886 return 887 } 888 889 traceID, spanID = sub[1], sub[2] 890 if spanID == "0" { 891 spanID = "" 892 } 893 traceSampled = sub[3] == "1" 894 895 return 896} 897 898func (l *Logger) toLogEntry(e Entry) (*logpb.LogEntry, error) { 899 if e.LogName != "" { 900 return nil, errors.New("logging: Entry.LogName should be not be set when writing") 901 } 902 t := e.Timestamp 903 if t.IsZero() { 904 t = now() 905 } 906 ts, err := ptypes.TimestampProto(t) 907 if err != nil { 908 return nil, err 909 } 910 if e.Trace == "" && e.HTTPRequest != nil && e.HTTPRequest.Request != nil { 911 traceHeader := e.HTTPRequest.Request.Header.Get("X-Cloud-Trace-Context") 912 if traceHeader != "" { 913 // Set to a relative resource name, as described at 914 // https://cloud.google.com/appengine/docs/flexible/go/writing-application-logs. 915 traceID, spanID, traceSampled := deconstructXCloudTraceContext(traceHeader) 916 if traceID != "" { 917 e.Trace = fmt.Sprintf("%s/traces/%s", l.client.parent, traceID) 918 } 919 if e.SpanID == "" { 920 e.SpanID = spanID 921 } 922 923 // If we previously hadn't set TraceSampled, let's retrieve it 924 // from the HTTP request's header, as per: 925 // https://cloud.google.com/trace/docs/troubleshooting#force-trace 926 e.TraceSampled = e.TraceSampled || traceSampled 927 } 928 } 929 ent := &logpb.LogEntry{ 930 Timestamp: ts, 931 Severity: logtypepb.LogSeverity(e.Severity), 932 InsertId: e.InsertID, 933 HttpRequest: fromHTTPRequest(e.HTTPRequest), 934 Operation: e.Operation, 935 Labels: e.Labels, 936 Trace: e.Trace, 937 SpanId: e.SpanID, 938 Resource: e.Resource, 939 SourceLocation: e.SourceLocation, 940 TraceSampled: e.TraceSampled, 941 } 942 switch p := e.Payload.(type) { 943 case string: 944 ent.Payload = &logpb.LogEntry_TextPayload{TextPayload: p} 945 default: 946 s, err := toProtoStruct(p) 947 if err != nil { 948 return nil, err 949 } 950 ent.Payload = &logpb.LogEntry_JsonPayload{JsonPayload: s} 951 } 952 return ent, nil 953} 954