Live video on the AT Protocol
stream.place
1/*
2Package clog provides Context with logging metadata, as well as logging helper functions.
3*/
4package log
5
6import (
7 "bufio"
8 "context"
9 "flag"
10 "fmt"
11 "log/slog"
12 "os"
13 "path/filepath"
14 "regexp"
15 "runtime"
16 "strconv"
17 "time"
18
19 "github.com/golang/glog"
20 "github.com/lmittmann/tint"
21 "github.com/mattn/go-isatty"
22)
23
24// unique type to prevent assignment.
25type clogContextKeyType struct{}
26
27// singleton value to identify our logging metadata in context
28var clogContextKey = clogContextKeyType{}
29
30// unique type to prevent assignment.
31type clogDebugKeyType struct{}
32
33// singleton value to identify our debug cli flag
34var clogDebugKey = clogDebugKeyType{}
35
36var errorLogLevel glog.Level = 1
37var warnLogLevel glog.Level = 2
38var defaultLogLevel glog.Level = 3
39var debugLogLevel glog.Level = 4
40var traceLogLevel glog.Level = 9
41
42// basic type to represent logging container. logging context is immutable after
43// creation, so we don't have to worry about locking.
44type metadata [][]string
45
46// LOG: I0809 17:23:01.775710 255904 broadcast.go:1162] manifestID=didplcdkh4rwafdcda4ko7lewe43ml-84zq1aff-4ren nonce=9899027318953397582 seqNo=2 clientIP=127.0.0.1 Trying to transcode segment using sessions=1
47// LOG: I0809 17:23:01.777792 255904 segment_rpc.go:551] manifestID=didplcdkh4rwafdcda4ko7lewe43ml-84zq1aff-4ren nonce=9899027318953397582 seqNo=2 orchSessionID=cdc9e3b9 orchestrator=https://127.0.0.1:9001 clientIP=127.0.0.1 Submitting segment bytes=1017268 orch=https://127.0.0.1:9001 timeout=8s uploadTimeout=2s segDur=0.832
48// LOG: I0809 17:23:01.778444 255904 discovery.go:211] manifestID=didplcdkh4rwafdcda4ko7lewe43ml-84zq1aff-4ren nonce=9899027318953397582 clientIP=127.0.0.1 Done fetching orch info numOrch=1 responses=1/1 timedOut=false
49// LOG: I0809 17:23:01.782914 255904 segment_rpc.go:587] manifestID=didplcdkh4rwafdcda4ko7lewe43ml-84zq1aff-4ren nonce=9899027318953397582 seqNo=2 orchSessionID=cdc9e3b9 orchestrator=https://127.0.0.1:9001 clientIP=127.0.0.1 Uploaded segment orch=https://127.0.0.1:9001 dur=5.106541ms
50// LOG: I0809 17:23:01.892735 255904 segment_rpc.go:668] manifestID=didplcdkh4rwafdcda4ko7lewe43ml-84zq1aff-4ren nonce=9899027318953397582 seqNo=2 orchSessionID=cdc9e3b9 orchestrator=https://127.0.0.1:9001 clientIP=127.0.0.1 Successfully transcoded segment segName= seqNo=2 orch=https://127.0.0.1:9001 dur=109.762457ms
51// LOG: I0809 17:23:01.893821 255904 mediaserver.go:1046] manifestID=didplcdkh4rwafdcda4ko7lewe43ml-84zq1aff-4ren nonce=9899027318953397582 seqNo=2 orchSessionID=cdc9e3b9 orchestrator=https://127.0.0.1:9001 clientIP=127.0.0.1 Finished transcoding push request at url=http://127.0.0.1:8935/live/didplcdkh4rwafdcda4ko7lewe43ml-84zq1aff-4ren/2.ts took=160.894832ms
52
53var realStderr = os.Stderr
54var logLineRegex = regexp.MustCompile(`^([IWEF])\d+ \d{2}:\d{2}:\d{2}\.\d{6}\s+\d+\s+([^:]+:\d+)\]\s*(.*)$`)
55
56func SetColorLogger(color string) {
57 noColor := false
58 if color == "true" {
59 noColor = false
60 } else if color == "false" {
61 noColor = true
62 } else {
63 noColor = !isatty.IsTerminal(realStderr.Fd())
64 }
65 // set global logger with custom options
66 slog.SetDefault(slog.New(
67 tint.NewHandler(realStderr, &tint.Options{
68 Level: slog.LevelDebug,
69 TimeFormat: time.RFC3339,
70 NoColor: noColor,
71 }),
72 ))
73}
74
75func MonkeypatchStderr() {
76 r, w, err := os.Pipe()
77 if err != nil {
78 panic(err)
79 }
80 realStderr := os.Stderr
81 os.Stderr = w
82 ctx := WithLogValues(context.Background(), "component", "livepeer")
83 go func() {
84 scanner := bufio.NewScanner(r)
85 for scanner.Scan() {
86 match := logLineRegex.FindStringSubmatch(scanner.Text())
87 if len(match) == 0 {
88 fmt.Fprintf(realStderr, "%s\n", scanner.Text())
89 continue
90 }
91 level := match[1]
92 caller := match[2]
93 message := match[3]
94 if level == "I" {
95 Log(ctx, message, "caller", caller)
96 } else if level == "W" {
97 Warn(ctx, message)
98 } else if level == "E" {
99 Error(ctx, message)
100 } else if level == "F" {
101 Warn(ctx, message)
102 } else {
103 fmt.Fprintf(realStderr, "UNKNOWN LOG LEVEL: %s %s\n", level, message)
104 }
105 }
106 if err := scanner.Err(); err != nil {
107 fmt.Fprintf(realStderr, "LOG: Error reading pipe: %v\n", err)
108 }
109
110 }()
111 // set global logger with custom options
112 SetColorLogger("")
113
114 // Set default v level to 3; this is overridden in main() but is useful for tests
115 vFlag := flag.Lookup("v")
116 // nolint:errcheck
117 vFlag.Value.Set(fmt.Sprintf("%d", defaultLogLevel))
118}
119
120type VerboseLogger struct {
121 level glog.Level
122}
123
124// implementation of our logger aware of glog -v=[0-9] levels
125func V(level glog.Level) *VerboseLogger {
126 return &VerboseLogger{level: level}
127}
128
129func (m metadata) Map() map[string]string {
130 out := map[string]string{}
131 for _, pair := range m {
132 out[pair[0]] = pair[1]
133 }
134 return out
135}
136
137func (m metadata) Flat() []any {
138 out := []any{}
139 for _, pair := range m {
140 out = append(out, pair[0])
141 out = append(out, pair[1])
142 }
143 return out
144}
145
146// Return a new context, adding in the provided values to the logging metadata
147func WithLogValues(ctx context.Context, args ...string) context.Context {
148 oldMetadata, _ := ctx.Value(clogContextKey).(metadata)
149 // No previous logging found, set up a new map
150 if oldMetadata == nil {
151 oldMetadata = metadata{}
152 }
153 var newMetadata = metadata{}
154 for _, pair := range oldMetadata {
155 newMetadata = append(newMetadata, []string{pair[0], pair[1]})
156 }
157 for i := range args {
158 if i%2 == 0 {
159 continue
160 }
161 newKey := args[i-1]
162 newValue := args[i]
163 found := false
164 for _, pair := range newMetadata {
165 if pair[0] == newKey {
166 pair[1] = newValue
167 found = true
168 break
169 }
170 }
171 if !found {
172 newMetadata = append(newMetadata, []string{newKey, newValue})
173 }
174 }
175 return context.WithValue(ctx, clogContextKey, newMetadata)
176}
177
178// Return a new context, adding in the provided values to the logging metadata
179func WithDebugValue(ctx context.Context, debug map[string]map[string]int) context.Context {
180 return context.WithValue(ctx, clogDebugKey, debug)
181}
182
183// Actual log handler; the others have wrappers to properly handle stack depth
184func (v *VerboseLogger) log(ctx context.Context, message string, fn func(string, ...any), args ...any) {
185 // I want a compile time assertion for this... but short of that let's be REALLY ANNOYING
186 if len(args)%2 != 0 {
187 for range 6 {
188 fmt.Println("!!!!!!!!!!!!!!!! FOLLOWING LOG LINE HAS AN ODD NUMBER OF ARGUMENTS !!!!!!!!!!!!!!!!")
189 }
190 }
191 meta, metaOk := ctx.Value(clogContextKey).(metadata)
192 found := false
193 highestLevel := glog.Level(0)
194 debug, debugOk := ctx.Value(clogDebugKey).(map[string]map[string]int)
195
196 // debug is {"func": {"ToHLS": 3}, "file": {"gstreamer.go": 4}}
197 // meta is {"func": "ToHLS", "file": "gstreamer.go"}
198 // we want to use the highest level between debug and meta
199 if debugOk && metaOk {
200 for mk, mv := range meta.Map() {
201 debugValuesForMetaValue, ok := debug[mk]
202 if !ok {
203 continue
204 }
205 ll, ok := debugValuesForMetaValue[mv]
206 if !ok {
207 continue
208 }
209 if glog.Level(ll) > highestLevel {
210 found = true
211 highestLevel = glog.Level(ll)
212 }
213 }
214 }
215 if found {
216 if v.level > highestLevel {
217 return
218 }
219 } else {
220 if !glog.V(v.level) {
221 return
222 }
223 }
224
225 hasCaller := false
226
227 allArgs := []any{}
228 allArgs = append(allArgs, args...)
229 allArgs = append(allArgs, meta.Flat()...)
230 for i := range args {
231 if i%2 == 0 {
232 continue
233 }
234 if args[i-1] == "caller" {
235 hasCaller = true
236 }
237 }
238 if !hasCaller {
239 allArgs = append(allArgs, "caller", caller(3))
240 }
241
242 fn(message, allArgs...)
243}
244
245func (v *VerboseLogger) Log(ctx context.Context, message string, args ...any) {
246 if v.level >= 4 {
247 v.log(ctx, message, slog.Debug, args...)
248 } else {
249 v.log(ctx, message, slog.Info, args...)
250 }
251}
252
253func Error(ctx context.Context, message string, args ...any) {
254 V(errorLogLevel).log(ctx, message, slog.Error, args...)
255}
256
257func Warn(ctx context.Context, message string, args ...any) {
258 V(warnLogLevel).log(ctx, message, slog.Warn, args...)
259}
260
261func Log(ctx context.Context, message string, args ...any) {
262 V(defaultLogLevel).log(ctx, message, slog.Info, args...)
263}
264
265func Debug(ctx context.Context, message string, args ...any) {
266 V(debugLogLevel).log(ctx, message, slog.Debug, args...)
267}
268
269func Trace(ctx context.Context, message string, args ...any) {
270 V(traceLogLevel).log(ctx, message, slog.Debug, args...)
271}
272
273// returns true if we are at least the given level
274func Level(level glog.Level) glog.Verbose {
275 return glog.V(level)
276}
277
278func GetValue(ctx context.Context, key string) string {
279 meta, metaOk := ctx.Value(clogContextKey).(metadata)
280 if !metaOk {
281 return ""
282 }
283 return meta.Map()[key]
284}
285
286// returns filenames relative to streamplace root
287// e.g. handlers/misttriggers/triggers.go:58
288func caller(depth int) string {
289 _, myfile, _, _ := runtime.Caller(0)
290 // This assumes that the root directory of streamplace is two levels above this folder.
291 // If that changes, please update this rootDir resolution.
292 rootDir := filepath.Join(filepath.Dir(myfile), "..", "..")
293 _, file, line, _ := runtime.Caller(depth)
294 rel, _ := filepath.Rel(rootDir, file)
295 return rel + ":" + strconv.Itoa(line)
296}