|
| 1 | +package funcframework |
| 2 | + |
| 3 | +import ( |
| 4 | + "bufio" |
| 5 | + "context" |
| 6 | + "encoding/json" |
| 7 | + "io" |
| 8 | + "net/http" |
| 9 | + "os" |
| 10 | + "regexp" |
| 11 | + "sync" |
| 12 | +) |
| 13 | + |
| 14 | +var ( |
| 15 | + loggingIDsContextKey contextKey = "loggingIDs" |
| 16 | + validXCloudTraceContext = regexp.MustCompile( |
| 17 | + // Matches on "TRACE_ID" |
| 18 | + `([a-f\d]+)?` + |
| 19 | + // Matches on "/SPAN_ID" |
| 20 | + `(?:/([a-f\d]+))?` + |
| 21 | + // Matches on ";0=TRACE_TRUE" |
| 22 | + `(?:;o=(\d))?`) |
| 23 | +) |
| 24 | + |
| 25 | +type loggingIDs struct { |
| 26 | + trace string |
| 27 | + spanID string |
| 28 | + executionID string |
| 29 | +} |
| 30 | + |
| 31 | +type contextKey string |
| 32 | + |
| 33 | +func addLoggingIDsToRequest(r *http.Request) *http.Request { |
| 34 | + executionID := r.Header.Get("Function-Execution-Id") |
| 35 | + traceID, spanID, _ := deconstructXCloudTraceContext(r.Header.Get("X-Cloud-Trace-Context")) |
| 36 | + |
| 37 | + if executionID == "" && traceID == "" && spanID == "" { |
| 38 | + return r |
| 39 | + } |
| 40 | + |
| 41 | + r = r.WithContext(contextWithLoggingIDs(r.Context(), &loggingIDs{ |
| 42 | + trace: traceID, |
| 43 | + spanID: spanID, |
| 44 | + executionID: executionID, |
| 45 | + })) |
| 46 | + |
| 47 | + return r |
| 48 | +} |
| 49 | + |
| 50 | +func contextWithLoggingIDs(ctx context.Context, loggingIDs *loggingIDs) context.Context { |
| 51 | + return context.WithValue(ctx, loggingIDsContextKey, loggingIDs) |
| 52 | +} |
| 53 | + |
| 54 | +func loggingIDsFromContext(ctx context.Context) *loggingIDs { |
| 55 | + val := ctx.Value(loggingIDsContextKey) |
| 56 | + if val == nil { |
| 57 | + return nil |
| 58 | + } |
| 59 | + return val.(*loggingIDs) |
| 60 | +} |
| 61 | + |
| 62 | +func TraceIDFromContext(ctx context.Context) string { |
| 63 | + ids := loggingIDsFromContext(ctx) |
| 64 | + if ids == nil { |
| 65 | + return "" |
| 66 | + } |
| 67 | + return ids.trace |
| 68 | +} |
| 69 | + |
| 70 | +func ExecutionIDFromContext(ctx context.Context) string { |
| 71 | + ids := loggingIDsFromContext(ctx) |
| 72 | + if ids == nil { |
| 73 | + return "" |
| 74 | + } |
| 75 | + return ids.executionID |
| 76 | +} |
| 77 | + |
| 78 | +func SpanIDFromContext(ctx context.Context) string { |
| 79 | + ids := loggingIDsFromContext(ctx) |
| 80 | + if ids == nil { |
| 81 | + return "" |
| 82 | + } |
| 83 | + return ids.spanID |
| 84 | +} |
| 85 | + |
| 86 | +func deconstructXCloudTraceContext(s string) (traceID, spanID string, traceSampled bool) { |
| 87 | + // As per the format described at https://cloud.google.com/trace/docs/setup#force-trace |
| 88 | + // "X-Cloud-Trace-Context: TRACE_ID/SPAN_ID;o=TRACE_TRUE" |
| 89 | + // for example: |
| 90 | + // "X-Cloud-Trace-Context: 105445aa7843bc8bf206b120001000/1;o=1" |
| 91 | + matches := validXCloudTraceContext.FindStringSubmatch(s) |
| 92 | + if matches != nil { |
| 93 | + traceID, spanID, traceSampled = matches[1], matches[2], matches[3] == "1" |
| 94 | + } |
| 95 | + if spanID == "0" { |
| 96 | + spanID = "" |
| 97 | + } |
| 98 | + return |
| 99 | +} |
| 100 | + |
| 101 | +// structuredLogEvent declares a subset of the fields supported by cloudlogging structured log events. |
| 102 | +// See https://cloud.google.com/logging/docs/structured-logging. |
| 103 | +type structuredLogEvent struct { |
| 104 | + Message string `json:"message"` |
| 105 | + Trace string `json:"logging.googleapis.com/trace,omitempty"` |
| 106 | + SpanID string `json:"logging.googleapis.com/spanId,omitempty"` |
| 107 | + Labels map[string]string `json:"logging.googleapis.com/labels,omitempty"` |
| 108 | +} |
| 109 | + |
| 110 | +// structuredLogWriter writes structured logs |
| 111 | +type structuredLogWriter struct { |
| 112 | + mu sync.Mutex |
| 113 | + w io.Writer |
| 114 | + loggingIDs loggingIDs |
| 115 | + buf []byte |
| 116 | +} |
| 117 | + |
| 118 | +func (w *structuredLogWriter) writeStructuredLog(loggingIDs loggingIDs, message string) (int, error) { |
| 119 | + event := structuredLogEvent{ |
| 120 | + Message: message, |
| 121 | + Trace: loggingIDs.trace, |
| 122 | + SpanID: loggingIDs.spanID, |
| 123 | + } |
| 124 | + if loggingIDs.executionID != "" { |
| 125 | + event.Labels = map[string]string{ |
| 126 | + "execution_id": loggingIDs.executionID, |
| 127 | + } |
| 128 | + } |
| 129 | + |
| 130 | + marshalled, err := json.Marshal(event) |
| 131 | + if err != nil { |
| 132 | + return 0, err |
| 133 | + } |
| 134 | + marshalled = append(marshalled, '\n') |
| 135 | + return w.w.Write(marshalled) |
| 136 | +} |
| 137 | + |
| 138 | +func (w *structuredLogWriter) Write(output []byte) (int, error) { |
| 139 | + w.mu.Lock() |
| 140 | + defer w.mu.Unlock() |
| 141 | + |
| 142 | + w.buf = append(w.buf, output...) |
| 143 | + buf := w.buf |
| 144 | + wroteLines := 0 |
| 145 | + for { |
| 146 | + advance, token, err := bufio.ScanLines(buf, false) |
| 147 | + if token == nil || err != nil { |
| 148 | + break |
| 149 | + } |
| 150 | + buf = buf[advance:] |
| 151 | + if _, err := w.writeStructuredLog(w.loggingIDs, string(token)); err != nil { |
| 152 | + return 0, err |
| 153 | + } |
| 154 | + wroteLines += 1 |
| 155 | + } |
| 156 | + |
| 157 | + if wroteLines > 0 { |
| 158 | + // Compact the buffer by copying remaining bytes to the start. |
| 159 | + w.buf = append(w.buf[:0], buf...) |
| 160 | + } |
| 161 | + |
| 162 | + return len(output), nil |
| 163 | +} |
| 164 | + |
| 165 | +func (w *structuredLogWriter) Close() error { |
| 166 | + if len(w.buf) == 0 { |
| 167 | + return nil |
| 168 | + } |
| 169 | + _, err := w.writeStructuredLog(w.loggingIDs, string(w.buf)) |
| 170 | + return err |
| 171 | +} |
| 172 | + |
| 173 | +// LogWriter returns an io.Writer as a log sink for the request context. |
| 174 | +// One log event is generated for each new line terminated byte sequence |
| 175 | +// written to the io.Writer. |
| 176 | +// |
| 177 | +// This can be used with common logging frameworks, for example: |
| 178 | +// |
| 179 | +// import ( |
| 180 | +// "log" |
| 181 | +// "github.com/GoogleCloudPlatform/functions-framework-go/funcframework" |
| 182 | +// ) |
| 183 | +// ... |
| 184 | +// func helloWorld(w http.ResponseWriter, r *http.Request) { |
| 185 | +// l := logger.New(funcframework.LogWriter(r.Context())) |
| 186 | +// l.Println("hello world!") |
| 187 | +// } |
| 188 | +func LogWriter(ctx context.Context) io.WriteCloser { |
| 189 | + loggingIDs := loggingIDsFromContext(ctx) |
| 190 | + if loggingIDs == nil { |
| 191 | + return os.Stderr |
| 192 | + } |
| 193 | + |
| 194 | + return &structuredLogWriter{ |
| 195 | + w: os.Stderr, |
| 196 | + loggingIDs: *loggingIDs, |
| 197 | + } |
| 198 | +} |
0 commit comments