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
18 "github.com/bluesky-social/indigo/util"
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 ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
70 if a.Key != "time" {
71 return a
72 }
73 t := a.Value.Time().UTC()
74 return slog.Attr{
75 Key: "time",
76 Value: slog.TimeValue(t),
77 }
78 },
79 TimeFormat: util.ISO8601,
80 NoColor: noColor,
81 }),
82 ))
83}
84
85func MonkeypatchStderr() {
86 r, w, err := os.Pipe()
87 if err != nil {
88 panic(err)
89 }
90 realStderr := os.Stderr
91 os.Stderr = w
92 ctx := WithLogValues(context.Background(), "component", "livepeer")
93 go func() {
94 scanner := bufio.NewScanner(r)
95 for scanner.Scan() {
96 match := logLineRegex.FindStringSubmatch(scanner.Text())
97 if len(match) == 0 {
98 fmt.Fprintf(realStderr, "%s\n", scanner.Text())
99 continue
100 }
101 level := match[1]
102 caller := match[2]
103 message := match[3]
104 if level == "I" {
105 Log(ctx, message, "caller", caller)
106 } else if level == "W" {
107 Warn(ctx, message)
108 } else if level == "E" {
109 Error(ctx, message)
110 } else if level == "F" {
111 Warn(ctx, message)
112 } else {
113 fmt.Fprintf(realStderr, "UNKNOWN LOG LEVEL: %s %s\n", level, message)
114 }
115 }
116 if err := scanner.Err(); err != nil {
117 fmt.Fprintf(realStderr, "LOG: Error reading pipe: %v\n", err)
118 }
119
120 }()
121 // set global logger with custom options
122 SetColorLogger("")
123
124 // Set default v level to 3; this is overridden in main() but is useful for tests
125 vFlag := flag.Lookup("v")
126 // nolint:errcheck
127 vFlag.Value.Set(fmt.Sprintf("%d", defaultLogLevel))
128}
129
130type VerboseLogger struct {
131 level glog.Level
132}
133
134// implementation of our logger aware of glog -v=[0-9] levels
135func V(level glog.Level) *VerboseLogger {
136 return &VerboseLogger{level: level}
137}
138
139func (m metadata) Map() map[string]string {
140 out := map[string]string{}
141 for _, pair := range m {
142 out[pair[0]] = pair[1]
143 }
144 return out
145}
146
147func (m metadata) Flat() []any {
148 out := []any{}
149 for _, pair := range m {
150 out = append(out, pair[0])
151 out = append(out, pair[1])
152 }
153 return out
154}
155
156// Return a new context, adding in the provided values to the logging metadata
157func WithLogValues(ctx context.Context, args ...string) context.Context {
158 oldMetadata, _ := ctx.Value(clogContextKey).(metadata)
159 // No previous logging found, set up a new map
160 if oldMetadata == nil {
161 oldMetadata = metadata{}
162 }
163 var newMetadata = metadata{}
164 for _, pair := range oldMetadata {
165 newMetadata = append(newMetadata, []string{pair[0], pair[1]})
166 }
167 for i := range args {
168 if i%2 == 0 {
169 continue
170 }
171 newKey := args[i-1]
172 newValue := args[i]
173 found := false
174 for _, pair := range newMetadata {
175 if pair[0] == newKey {
176 pair[1] = newValue
177 found = true
178 break
179 }
180 }
181 if !found {
182 newMetadata = append(newMetadata, []string{newKey, newValue})
183 }
184 }
185 return context.WithValue(ctx, clogContextKey, newMetadata)
186}
187
188// Return a new context, adding in the provided values to the logging metadata
189func WithDebugValue(ctx context.Context, debug map[string]map[string]int) context.Context {
190 return context.WithValue(ctx, clogDebugKey, debug)
191}
192
193// Actual log handler; the others have wrappers to properly handle stack depth
194func (v *VerboseLogger) log(ctx context.Context, message string, fn func(string, ...any), args ...any) {
195 // I want a compile time assertion for this... but short of that let's be REALLY ANNOYING
196 if len(args)%2 != 0 {
197 for range 6 {
198 fmt.Println("!!!!!!!!!!!!!!!! FOLLOWING LOG LINE HAS AN ODD NUMBER OF ARGUMENTS !!!!!!!!!!!!!!!!")
199 }
200 }
201 meta, metaOk := ctx.Value(clogContextKey).(metadata)
202 found := false
203 highestLevel := glog.Level(0)
204 debug, debugOk := ctx.Value(clogDebugKey).(map[string]map[string]int)
205
206 // debug is {"func": {"ToHLS": 3}, "file": {"gstreamer.go": 4}}
207 // meta is {"func": "ToHLS", "file": "gstreamer.go"}
208 // we want to use the highest level between debug and meta
209 if debugOk && metaOk {
210 for mk, mv := range meta.Map() {
211 debugValuesForMetaValue, ok := debug[mk]
212 if !ok {
213 continue
214 }
215 ll, ok := debugValuesForMetaValue[mv]
216 if !ok {
217 continue
218 }
219 if glog.Level(ll) > highestLevel {
220 found = true
221 highestLevel = glog.Level(ll)
222 }
223 }
224 }
225 if found {
226 if v.level > highestLevel {
227 return
228 }
229 } else {
230 if !glog.V(v.level) {
231 return
232 }
233 }
234
235 hasCaller := false
236
237 allArgs := []any{}
238 allArgs = append(allArgs, args...)
239 allArgs = append(allArgs, meta.Flat()...)
240 for i := range args {
241 if i%2 == 0 {
242 continue
243 }
244 if args[i-1] == "caller" {
245 hasCaller = true
246 }
247 }
248 if !hasCaller {
249 allArgs = append(allArgs, "caller", caller(3))
250 }
251
252 fn(message, allArgs...)
253}
254
255func (v *VerboseLogger) Log(ctx context.Context, message string, args ...any) {
256 if v.level >= 4 {
257 v.log(ctx, message, slog.Debug, args...)
258 } else {
259 v.log(ctx, message, slog.Info, args...)
260 }
261}
262
263func Error(ctx context.Context, message string, args ...any) {
264 V(errorLogLevel).log(ctx, message, slog.Error, args...)
265}
266
267func Warn(ctx context.Context, message string, args ...any) {
268 V(warnLogLevel).log(ctx, message, slog.Warn, args...)
269}
270
271func Log(ctx context.Context, message string, args ...any) {
272 V(defaultLogLevel).log(ctx, message, slog.Info, args...)
273}
274
275func Debug(ctx context.Context, message string, args ...any) {
276 V(debugLogLevel).log(ctx, message, slog.Info, args...)
277}
278
279func Trace(ctx context.Context, message string, args ...any) {
280 V(traceLogLevel).log(ctx, message, slog.Info, args...)
281}
282
283// returns true if we are at least the given level
284func Level(level glog.Level) glog.Verbose {
285 return glog.V(level)
286}
287
288func GetValue(ctx context.Context, key string) string {
289 meta, metaOk := ctx.Value(clogContextKey).(metadata)
290 if !metaOk {
291 return ""
292 }
293 return meta.Map()[key]
294}
295
296// returns filenames relative to streamplace root
297// e.g. handlers/misttriggers/triggers.go:58
298func caller(depth int) string {
299 _, myfile, _, _ := runtime.Caller(0)
300 // This assumes that the root directory of streamplace is two levels above this folder.
301 // If that changes, please update this rootDir resolution.
302 rootDir := filepath.Join(filepath.Dir(myfile), "..", "..")
303 _, file, line, _ := runtime.Caller(depth)
304 rel, _ := filepath.Rel(rootDir, file)
305 return rel + ":" + strconv.Itoa(line)
306}