blob: 5738adcf462f6f33cf4c1757f5e392c3a822f342 [file] [log] [blame]
// Copyright 2016 Google Inc. All Rights Reserved.
// Licensed under the Apache License, Version 2.0 (the "License");
// you may not use this file except in compliance with the License.
// You may obtain a copy of the License at
// Unless required by applicable law or agreed to in writing, software
// distributed under the License is distributed on an "AS IS" BASIS,
// See the License for the specific language governing permissions and
// limitations under the License.
// API/gRPC features intentionally missing from this client:
// - You cannot have the server pick the time of the entry. This client
// always sends a time.
// - There is no way to provide a protocol buffer payload.
// - No support for the "partial success" feature when writing log entries.
// TODO(jba): test whether forward-slash characters in the log ID must be URL-encoded.
// These features are missing now, but will likely be added:
// - There is no way to specify CallOptions.
package logging
import (
vkit ""
structpb ""
tspb ""
mrpb ""
logtypepb ""
logpb ""
const (
// Scope for reading from the logging service.
ReadScope = ""
// Scope for writing to the logging service.
WriteScope = ""
// Scope for administrative actions on the logging service.
AdminScope = ""
const (
// defaultErrorCapacity is the capacity of the channel used to deliver
// errors to the OnError function.
defaultErrorCapacity = 10
// DefaultDelayThreshold is the default value for the DelayThreshold LoggerOption.
DefaultDelayThreshold = time.Second
// DefaultEntryCountThreshold is the default value for the EntryCountThreshold LoggerOption.
DefaultEntryCountThreshold = 1000
// DefaultEntryByteThreshold is the default value for the EntryByteThreshold LoggerOption.
DefaultEntryByteThreshold = 1 << 20 // 1MiB
// DefaultBufferedByteLimit is the default value for the BufferedByteLimit LoggerOption.
DefaultBufferedByteLimit = 1 << 30 // 1GiB
// For testing:
var now = time.Now
// ErrOverflow signals that the number of buffered entries for a Logger
// exceeds its BufferLimit.
var ErrOverflow = bundler.ErrOverflow
// ErrOversizedEntry signals that an entry's size exceeds the maximum number of
// bytes that will be sent in a single call to the logging service.
var ErrOversizedEntry = bundler.ErrOversizedItem
// Client is a Logging client. A Client is associated with a single Cloud project.
type Client struct {
client *vkit.Client // client for the logging service
projectID string
errc chan error // should be buffered to minimize dropped errors
donec chan struct{} // closed on Client.Close to close Logger bundlers
loggers sync.WaitGroup // so we can wait for loggers to close
closed bool
mu sync.Mutex
nErrs int // number of errors we saw
lastErr error // last error we saw
// OnError is called when an error occurs in a call to Log or Flush. The
// error may be due to an invalid Entry, an overflow because BufferLimit
// was reached (in which case the error will be ErrOverflow) or an error
// communicating with the logging service. OnError is called with errors
// from all Loggers. It is never called concurrently. OnError is expected
// to return quickly; if errors occur while OnError is running, some may
// not be reported. The default behavior is to call log.Printf.
// This field should be set only once, before any method of Client is called.
OnError func(err error)
// NewClient returns a new logging client associated with the provided project ID.
// By default NewClient uses WriteScope. To use a different scope, call
// NewClient using a WithScopes option (see
func NewClient(ctx context.Context, projectID string, opts ...option.ClientOption) (*Client, error) {
// Check for '/' in project ID to reserve the ability to support various owning resources,
// in the form "{Collection}/{Name}", for instance "organizations/my-org".
if strings.ContainsRune(projectID, '/') {
return nil, errors.New("logging: project ID contains '/'")
opts = append([]option.ClientOption{
}, opts...)
c, err := vkit.NewClient(ctx, opts...)
if err != nil {
return nil, err
c.SetGoogleClientInfo("gccl", version.Repo)
client := &Client{
client: c,
projectID: projectID,
errc: make(chan error, defaultErrorCapacity), // create a small buffer for errors
donec: make(chan struct{}),
OnError: func(e error) { log.Printf("logging client: %v", e) },
// Call the user's function synchronously, to make life easier for them.
go func() {
for err := range client.errc {
// This reference to OnError is memory-safe if the user sets OnError before
// calling any client methods. The reference happens before the first read from
// client.errc, which happens before the first write to client.errc, which
// happens before any call, which happens before the user sets OnError.
if fn := client.OnError; fn != nil {
} else {
log.Printf("logging (project ID %q): %v", projectID, err)
return client, nil
// parent returns the string used in many RPCs to denote the parent resource of the log.
func (c *Client) parent() string {
return "projects/" + c.projectID
var unixZeroTimestamp *tspb.Timestamp
func init() {
var err error
unixZeroTimestamp, err = ptypes.TimestampProto(time.Unix(0, 0))
if err != nil {
// Ping reports whether the client's connection to the logging service and the
// authentication configuration are valid. To accomplish this, Ping writes a
// log entry "ping" to a log named "ping".
func (c *Client) Ping(ctx context.Context) error {
ent := &logpb.LogEntry{
Payload: &logpb.LogEntry_TextPayload{TextPayload: "ping"},
Timestamp: unixZeroTimestamp, // Identical timestamps and insert IDs are both
InsertId: "ping", // necessary for the service to dedup these entries.
_, err := c.client.WriteLogEntries(ctx, &logpb.WriteLogEntriesRequest{
LogName: internal.LogPath(c.parent(), "ping"),
Resource: globalResource(c.projectID),
Entries: []*logpb.LogEntry{ent},
return err
// error puts the error on the client's error channel
// without blocking, and records summary error info.
func (c *Client) error(err error) {
select {
case c.errc <- err:
c.lastErr = err
func (c *Client) extractErrorInfo() error {
var err error
if c.lastErr != nil {
err = fmt.Errorf("saw %d errors; last: %v", c.nErrs, c.lastErr)
c.nErrs = 0
c.lastErr = nil
return err
// A Logger is used to write log messages to a single log. It can be configured
// with a log ID, common monitored resource, and a set of common labels.
type Logger struct {
client *Client
logName string // "projects/{projectID}/logs/{logID}"
stdLoggers map[Severity]*log.Logger
bundler *bundler.Bundler
// Options
commonResource *mrpb.MonitoredResource
commonLabels map[string]string
// A LoggerOption is a configuration option for a Logger.
type LoggerOption interface {
// CommonResource sets the monitored resource associated with all log entries
// written from a Logger. If not provided, the resource is automatically
// detected based on the running environment. This value can be overridden
// per-entry by setting an Entry's Resource field.
func CommonResource(r *mrpb.MonitoredResource) LoggerOption { return commonResource{r} }
type commonResource struct{ *mrpb.MonitoredResource }
func (r commonResource) set(l *Logger) { l.commonResource = r.MonitoredResource }
var detectedResource struct {
pb *mrpb.MonitoredResource
once sync.Once
func detectResource() *mrpb.MonitoredResource {
detectedResource.once.Do(func() {
if !metadata.OnGCE() {
projectID, err := metadata.ProjectID()
if err != nil {
id, err := metadata.InstanceID()
if err != nil {
zone, err := metadata.Zone()
if err != nil {
detectedResource.pb = &mrpb.MonitoredResource{
Type: "gce_instance",
Labels: map[string]string{
"project_id": projectID,
"instance_id": id,
"zone": zone,
return detectedResource.pb
func globalResource(projectID string) *mrpb.MonitoredResource {
return &mrpb.MonitoredResource{
Type: "global",
Labels: map[string]string{
"project_id": projectID,
// CommonLabels are labels that apply to all log entries written from a Logger,
// so that you don't have to repeat them in each log entry's Labels field. If
// any of the log entries contains a (key, value) with the same key that is in
// CommonLabels, then the entry's (key, value) overrides the one in
// CommonLabels.
func CommonLabels(m map[string]string) LoggerOption { return commonLabels(m) }
type commonLabels map[string]string
func (c commonLabels) set(l *Logger) { l.commonLabels = c }
// DelayThreshold is the maximum amount of time that an entry should remain
// buffered in memory before a call to the logging service is triggered. Larger
// values of DelayThreshold will generally result in fewer calls to the logging
// service, while increasing the risk that log entries will be lost if the
// process crashes.
// The default is DefaultDelayThreshold.
func DelayThreshold(d time.Duration) LoggerOption { return delayThreshold(d) }
type delayThreshold time.Duration
func (d delayThreshold) set(l *Logger) { l.bundler.DelayThreshold = time.Duration(d) }
// EntryCountThreshold is the maximum number of entries that will be buffered
// in memory before a call to the logging service is triggered. Larger values
// will generally result in fewer calls to the logging service, while
// increasing both memory consumption and the risk that log entries will be
// lost if the process crashes.
// The default is DefaultEntryCountThreshold.
func EntryCountThreshold(n int) LoggerOption { return entryCountThreshold(n) }
type entryCountThreshold int
func (e entryCountThreshold) set(l *Logger) { l.bundler.BundleCountThreshold = int(e) }
// EntryByteThreshold is the maximum number of bytes of entries that will be
// buffered in memory before a call to the logging service is triggered. See
// EntryCountThreshold for a discussion of the tradeoffs involved in setting
// this option.
// The default is DefaultEntryByteThreshold.
func EntryByteThreshold(n int) LoggerOption { return entryByteThreshold(n) }
type entryByteThreshold int
func (e entryByteThreshold) set(l *Logger) { l.bundler.BundleByteThreshold = int(e) }
// EntryByteLimit is the maximum number of bytes of entries that will be sent
// in a single call to the logging service. ErrOversizedEntry is returned if an
// entry exceeds EntryByteLimit. This option limits the size of a single RPC
// payload, to account for network or service issues with large RPCs. If
// EntryByteLimit is smaller than EntryByteThreshold, the latter has no effect.
// The default is zero, meaning there is no limit.
func EntryByteLimit(n int) LoggerOption { return entryByteLimit(n) }
type entryByteLimit int
func (e entryByteLimit) set(l *Logger) { l.bundler.BundleByteLimit = int(e) }
// BufferedByteLimit is the maximum number of bytes that the Logger will keep
// in memory before returning ErrOverflow. This option limits the total memory
// consumption of the Logger (but note that each Logger has its own, separate
// limit). It is possible to reach BufferedByteLimit even if it is larger than
// EntryByteThreshold or EntryByteLimit, because calls triggered by the latter
// two options may be enqueued (and hence occupying memory) while new log
// entries are being added.
// The default is DefaultBufferedByteLimit.
func BufferedByteLimit(n int) LoggerOption { return bufferedByteLimit(n) }
type bufferedByteLimit int
func (b bufferedByteLimit) set(l *Logger) { l.bundler.BufferedByteLimit = int(b) }
// Logger returns a Logger that will write entries with the given log ID, such as
// "syslog". A log ID must be less than 512 characters long and can only
// include the following characters: upper and lower case alphanumeric
// characters: [A-Za-z0-9]; and punctuation characters: forward-slash,
// underscore, hyphen, and period.
func (c *Client) Logger(logID string, opts ...LoggerOption) *Logger {
r := detectResource()
if r == nil {
r = globalResource(c.projectID)
l := &Logger{
client: c,
logName: internal.LogPath(c.parent(), logID),
commonResource: r,
// TODO(jba): determine the right context for the bundle handler.
ctx := context.TODO()
l.bundler = bundler.NewBundler(&logpb.LogEntry{}, func(entries interface{}) {
l.writeLogEntries(ctx, entries.([]*logpb.LogEntry))
l.bundler.DelayThreshold = DefaultDelayThreshold
l.bundler.BundleCountThreshold = DefaultEntryCountThreshold
l.bundler.BundleByteThreshold = DefaultEntryByteThreshold
l.bundler.BufferedByteLimit = DefaultBufferedByteLimit
for _, opt := range opts {
l.stdLoggers = map[Severity]*log.Logger{}
for s := range severityName {
l.stdLoggers[s] = log.New(severityWriter{l, s}, "", 0)
go func() {
defer c.loggers.Done()
return l
type severityWriter struct {
l *Logger
s Severity
func (w severityWriter) Write(p []byte) (n int, err error) {
Severity: w.s,
Payload: string(p),
return len(p), nil
// Close waits for all opened loggers to be flushed and closes the client.
func (c *Client) Close() error {
if c.closed {
return nil
close(c.donec) // close Logger bundlers
c.loggers.Wait() // wait for all bundlers to flush and close
// Now there can be no more errors.
close(c.errc) // terminate error goroutine
// Prefer logging errors to close errors.
err := c.extractErrorInfo()
err2 := c.client.Close()
if err == nil {
err = err2
c.closed = true
return err
// Severity is the severity of the event described in a log entry. These
// guideline severity levels are ordered, with numerically smaller levels
// treated as less severe than numerically larger levels.
type Severity int
const (
// Default means the log entry has no assigned severity level.
Default = Severity(logtypepb.LogSeverity_DEFAULT)
// Debug means debug or trace information.
Debug = Severity(logtypepb.LogSeverity_DEBUG)
// Info means routine information, such as ongoing status or performance.
Info = Severity(logtypepb.LogSeverity_INFO)
// Notice means normal but significant events, such as start up, shut down, or configuration.
Notice = Severity(logtypepb.LogSeverity_NOTICE)
// Warning means events that might cause problems.
Warning = Severity(logtypepb.LogSeverity_WARNING)
// Error means events that are likely to cause problems.
Error = Severity(logtypepb.LogSeverity_ERROR)
// Critical means events that cause more severe problems or brief outages.
Critical = Severity(logtypepb.LogSeverity_CRITICAL)
// Alert means a person must take an action immediately.
Alert = Severity(logtypepb.LogSeverity_ALERT)
// Emergency means one or more systems are unusable.
Emergency = Severity(logtypepb.LogSeverity_EMERGENCY)
var severityName = map[Severity]string{
Default: "Default",
Debug: "Debug",
Info: "Info",
Notice: "Notice",
Warning: "Warning",
Error: "Error",
Critical: "Critical",
Alert: "Alert",
Emergency: "Emergency",
// String converts a severity level to a string.
func (v Severity) String() string {
// same as proto.EnumName
s, ok := severityName[v]
if ok {
return s
return strconv.Itoa(int(v))
// ParseSeverity returns the Severity whose name equals s, ignoring case. It
// returns Default if no Severity matches.
func ParseSeverity(s string) Severity {
sl := strings.ToLower(s)
for sev, name := range severityName {
if strings.ToLower(name) == sl {
return sev
return Default
// Entry is a log entry.
// See for more about entries.
type Entry struct {
// Timestamp is the time of the entry. If zero, the current time is used.
Timestamp time.Time
// Severity is the entry's severity level.
// The zero value is Default.
Severity Severity
// Payload must be either a string or something that
// marshals via the encoding/json package to a JSON object
// (and not any other type of JSON value).
Payload interface{}
// Labels optionally specifies key/value labels for the log entry.
// The Logger.Log method takes ownership of this map. See Logger.CommonLabels
// for more about labels.
Labels map[string]string
// InsertID is a unique ID for the log entry. If you provide this field,
// the logging service considers other log entries in the same log with the
// same ID as duplicates which can be removed. If omitted, the logging
// service will generate a unique ID for this log entry. Note that because
// this client retries RPCs automatically, it is possible (though unlikely)
// that an Entry without an InsertID will be written more than once.
InsertID string
// HTTPRequest optionally specifies metadata about the HTTP request
// associated with this log entry, if applicable. It is optional.
HTTPRequest *HTTPRequest
// Operation optionally provides information about an operation associated
// with the log entry, if applicable.
Operation *logpb.LogEntryOperation
// LogName is the full log name, in the form
// "projects/{ProjectID}/logs/{LogID}". It is set by the client when
// reading entries. It is an error to set it when writing entries.
LogName string
// Resource is the monitored resource associated with the entry. It is set
// by the client when reading entries. It is an error to set it when
// writing entries.
Resource *mrpb.MonitoredResource
// Trace is the resource name of the trace associated with the log entry,
// if any. If it contains a relative resource name, the name is assumed to
// be relative to //
Trace string
// HTTPRequest contains an http.Request as well as additional
// information about the request and its response.
type HTTPRequest struct {
// Request is the http.Request passed to the handler.
Request *http.Request
// RequestSize is the size of the HTTP request message in bytes, including
// the request headers and the request body.
RequestSize int64
// Status is the response code indicating the status of the response.
// Examples: 200, 404.
Status int
// ResponseSize is the size of the HTTP response message sent back to the client, in bytes,
// including the response headers and the response body.
ResponseSize int64
// Latency is the request processing latency on the server, from the time the request was
// received until the response was sent.
Latency time.Duration
// LocalIP is the IP address (IPv4 or IPv6) of the origin server that the request
// was sent to.
LocalIP string
// RemoteIP is the IP address (IPv4 or IPv6) of the client that issued the
// HTTP request. Examples: "", "FE80::0202:B3FF:FE1E:8329".
RemoteIP string
// CacheHit reports whether an entity was served from cache (with or without
// validation).
CacheHit bool
// CacheValidatedWithOriginServer reports whether the response was
// validated with the origin server before being served from cache. This
// field is only meaningful if CacheHit is true.
CacheValidatedWithOriginServer bool
func fromHTTPRequest(r *HTTPRequest) *logtypepb.HttpRequest {
if r == nil {
return nil
if r.Request == nil {
panic("HTTPRequest must have a non-nil Request")
u := *r.Request.URL
u.Fragment = ""
pb := &logtypepb.HttpRequest{
RequestMethod: r.Request.Method,
RequestUrl: u.String(),
RequestSize: r.RequestSize,
Status: int32(r.Status),
ResponseSize: r.ResponseSize,
UserAgent: r.Request.UserAgent(),
ServerIp: r.LocalIP,
RemoteIp: r.RemoteIP, // TODO(jba): attempt to parse http.Request.RemoteAddr?
Referer: r.Request.Referer(),
CacheHit: r.CacheHit,
CacheValidatedWithOriginServer: r.CacheValidatedWithOriginServer,
if r.Latency != 0 {
pb.Latency = ptypes.DurationProto(r.Latency)
return pb
// toProtoStruct converts v, which must marshal into a JSON object,
// into a Google Struct proto.
func toProtoStruct(v interface{}) (*structpb.Struct, error) {
// Fast path: if v is already a *structpb.Struct, nothing to do.
if s, ok := v.(*structpb.Struct); ok {
return s, nil
// v is a Go struct that supports JSON marshalling. We want a Struct
// protobuf. Some day we may have a more direct way to get there, but right
// now the only way is to marshal the Go struct to JSON, unmarshal into a
// map, and then build the Struct proto from the map.
jb, err := json.Marshal(v)
if err != nil {
return nil, fmt.Errorf("logging: json.Marshal: %v", err)
var m map[string]interface{}
err = json.Unmarshal(jb, &m)
if err != nil {
return nil, fmt.Errorf("logging: json.Unmarshal: %v", err)
return jsonMapToProtoStruct(m), nil
func jsonMapToProtoStruct(m map[string]interface{}) *structpb.Struct {
fields := map[string]*structpb.Value{}
for k, v := range m {
fields[k] = jsonValueToStructValue(v)
return &structpb.Struct{Fields: fields}
func jsonValueToStructValue(v interface{}) *structpb.Value {
switch x := v.(type) {
case bool:
return &structpb.Value{Kind: &structpb.Value_BoolValue{BoolValue: x}}
case float64:
return &structpb.Value{Kind: &structpb.Value_NumberValue{NumberValue: x}}
case string:
return &structpb.Value{Kind: &structpb.Value_StringValue{StringValue: x}}
case nil:
return &structpb.Value{Kind: &structpb.Value_NullValue{}}
case map[string]interface{}:
return &structpb.Value{Kind: &structpb.Value_StructValue{StructValue: jsonMapToProtoStruct(x)}}
case []interface{}:
var vals []*structpb.Value
for _, e := range x {
vals = append(vals, jsonValueToStructValue(e))
return &structpb.Value{Kind: &structpb.Value_ListValue{ListValue: &structpb.ListValue{Values: vals}}}
panic(fmt.Sprintf("bad type %T for JSON value", v))
// LogSync logs the Entry synchronously without any buffering. Because LogSync is slow
// and will block, it is intended primarily for debugging or critical errors.
// Prefer Log for most uses.
// TODO(jba): come up with a better name (LogNow?) or eliminate.
func (l *Logger) LogSync(ctx context.Context, e Entry) error {
ent, err := toLogEntry(e)
if err != nil {
return err
_, err = l.client.client.WriteLogEntries(ctx, &logpb.WriteLogEntriesRequest{
LogName: l.logName,
Resource: l.commonResource,
Labels: l.commonLabels,
Entries: []*logpb.LogEntry{ent},
return err
// Log buffers the Entry for output to the logging service. It never blocks.
func (l *Logger) Log(e Entry) {
ent, err := toLogEntry(e)
if err != nil {
if err := l.bundler.Add(ent, proto.Size(ent)); err != nil {
// Flush blocks until all currently buffered log entries are sent.
// If any errors occurred since the last call to Flush from any Logger, or the
// creation of the client if this is the first call, then Flush returns a non-nil
// error with summary information about the errors. This information is unlikely to
// be actionable. For more accurate error reporting, set Client.OnError.
func (l *Logger) Flush() error {
return l.client.extractErrorInfo()
func (l *Logger) writeLogEntries(ctx context.Context, entries []*logpb.LogEntry) {
req := &logpb.WriteLogEntriesRequest{
LogName: l.logName,
Resource: l.commonResource,
Labels: l.commonLabels,
Entries: entries,
_, err := l.client.client.WriteLogEntries(ctx, req)
if err != nil {
// StandardLogger returns a *log.Logger for the provided severity.
// This method is cheap. A single log.Logger is pre-allocated for each
// severity level in each Logger. Callers may mutate the returned log.Logger
// (for example by calling SetFlags or SetPrefix).
func (l *Logger) StandardLogger(s Severity) *log.Logger { return l.stdLoggers[s] }
func trunc32(i int) int32 {
if i > math.MaxInt32 {
i = math.MaxInt32
return int32(i)
func toLogEntry(e Entry) (*logpb.LogEntry, error) {
if e.LogName != "" {
return nil, errors.New("logging: Entry.LogName should be not be set when writing")
t := e.Timestamp
if t.IsZero() {
t = now()
ts, err := ptypes.TimestampProto(t)
if err != nil {
return nil, err
ent := &logpb.LogEntry{
Timestamp: ts,
Severity: logtypepb.LogSeverity(e.Severity),
InsertId: e.InsertID,
HttpRequest: fromHTTPRequest(e.HTTPRequest),
Operation: e.Operation,
Labels: e.Labels,
Trace: e.Trace,
switch p := e.Payload.(type) {
case string:
ent.Payload = &logpb.LogEntry_TextPayload{TextPayload: p}
s, err := toProtoStruct(p)
if err != nil {
return nil, err
ent.Payload = &logpb.LogEntry_JsonPayload{JsonPayload: s}
return ent, nil