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