+6 -3

cmd/bigsky/main.go

reviewed

··· 229 229 env = "dev" 230 230 } 231 231 if cctx.Bool("jaeger") { 232 232 - url := "http://localhost:14268/api/traces" 233 233 - exp, err := jaeger.New(jaeger.WithCollectorEndpoint(jaeger.WithEndpoint(url))) 232 232 + jaegerUrl := "http://localhost:14268/api/traces" 233 233 + exp, err := jaeger.New(jaeger.WithCollectorEndpoint(jaeger.WithEndpoint(jaegerUrl))) 234 234 if err != nil { 235 235 return err 236 236 } ··· 294 294 signals := make(chan os.Signal, 1) 295 295 signal.Notify(signals, syscall.SIGINT, syscall.SIGTERM) 296 296 297 297 - // TODO: set slog default from param/env 297 297 + _, err := cliutil.SetupSlog(cliutil.LogOptions{}) 298 298 + if err != nil { 299 299 + return err 300 300 + } 298 301 299 302 // start observability/tracing (OTEL and jaeger) 300 303 if err := setupOTEL(cctx); err != nil {

+6 -1

cmd/gosky/main.go

reviewed

··· 81 81 }, 82 82 } 83 83 84 84 - // TODO: slog.SetDefault from param/env 84 84 + _, err := cliutil.SetupSlog(cliutil.LogOptions{}) 85 85 + if err != nil { 86 86 + fmt.Fprintf(os.Stderr, "logging setup error: %s\n", err.Error()) 87 87 + os.Exit(1) 88 88 + return 89 89 + } 85 90 86 91 app.Commands = []*cli.Command{ 87 92 accountCmd,

+307

util/cliutil/util.go

reviewed

··· 2 2 3 3 import ( 4 4 "encoding/json" 5 5 + "errors" 5 6 "fmt" 7 7 + "io" 8 8 + "io/fs" 9 9 + "log/slog" 6 10 "net/http" 7 11 "os" 8 12 "path/filepath" 13 13 + "regexp" 14 14 + "sort" 15 15 + "strconv" 9 16 "strings" 10 17 "time" 11 18 ··· 230 237 231 238 return db, nil 232 239 } 240 240 + 241 241 + type LogOptions struct { 242 242 + // e.g. 1_000_000_000 243 243 + LogRotateBytes int64 244 244 + 245 245 + // path to write to, if rotating, %T gets UnixMilli at file open time 246 246 + // NOTE: substitution is simple replace("%T", "") 247 247 + LogPath string 248 248 + 249 249 + // text|json 250 250 + LogFormat string 251 251 + 252 252 + // info|debug|warn|error 253 253 + LogLevel string 254 254 + 255 255 + // Keep N old logs (not including current); <0 disables removal, 0==remove all old log files immediately 256 256 + KeepOld int 257 257 + } 258 258 + 259 259 + // SetupSlog integrates passed in options and env vars. 260 260 + // 261 261 + // passing default cliutil.LogOptions{} is ok. 262 262 + // 263 263 + // GOLOG_LOG_LEVEL=info|debug|warn|error 264 264 + // 265 265 + // GOLOG_LOG_FMT=text|json 266 266 + // 267 267 + // GOLOG_FILE=path (or "-" or "" for stdout), %T gets UnixMilli; if a path with '/', {prefix}/current becomes a link to active log file 268 268 + // 269 269 + // GOLOG_ROTATE_BYTES=int maximum size of log chunk before rotating 270 270 + // 271 271 + // GOLOG_ROTATE_KEEP=int keep N olg logs (not including current) 272 272 + // 273 273 + // (env vars derived from ipfs logging library) 274 274 + func SetupSlog(options LogOptions) (*slog.Logger, error) { 275 275 + var hopts slog.HandlerOptions 276 276 + hopts.Level = slog.LevelInfo 277 277 + hopts.AddSource = true 278 278 + if options.LogLevel == "" { 279 279 + options.LogLevel = os.Getenv("GOLOG_LOG_LEVEL") 280 280 + } 281 281 + if options.LogLevel == "" { 282 282 + hopts.Level = slog.LevelInfo 283 283 + options.LogLevel = "info" 284 284 + } else { 285 285 + level := strings.ToLower(options.LogLevel) 286 286 + switch level { 287 287 + case "debug": 288 288 + hopts.Level = slog.LevelDebug 289 289 + case "info": 290 290 + hopts.Level = slog.LevelInfo 291 291 + case "warn": 292 292 + hopts.Level = slog.LevelWarn 293 293 + case "error": 294 294 + hopts.Level = slog.LevelError 295 295 + default: 296 296 + return nil, fmt.Errorf("unknown log level: %#v", options.LogLevel) 297 297 + } 298 298 + } 299 299 + if options.LogFormat == "" { 300 300 + options.LogFormat = os.Getenv("GOLOG_LOG_FMT") 301 301 + } 302 302 + if options.LogFormat == "" { 303 303 + options.LogFormat = "text" 304 304 + } else { 305 305 + format := strings.ToLower(options.LogFormat) 306 306 + if format == "json" || format == "text" { 307 307 + // ok 308 308 + } else { 309 309 + return nil, fmt.Errorf("invalid log format: %#v", options.LogFormat) 310 310 + } 311 311 + options.LogFormat = format 312 312 + } 313 313 + 314 314 + if options.LogPath == "" { 315 315 + options.LogPath = os.Getenv("GOLOG_FILE") 316 316 + } 317 317 + if options.LogRotateBytes == 0 { 318 318 + rotateBytesStr := os.Getenv("GOLOG_ROTATE_BYTES") 319 319 + if rotateBytesStr != "" { 320 320 + rotateBytes, err := strconv.ParseInt(rotateBytesStr, 10, 64) 321 321 + if err != nil { 322 322 + return nil, fmt.Errorf("invalid GOLOG_ROTATE_BYTES value: %w", err) 323 323 + } 324 324 + options.LogRotateBytes = rotateBytes 325 325 + } 326 326 + } 327 327 + if options.KeepOld == 0 { 328 328 + keepOldUnset := true 329 329 + keepOldStr := os.Getenv("GOLOG_ROTATE_KEEP") 330 330 + if keepOldStr != "" { 331 331 + keepOld, err := strconv.ParseInt(keepOldStr, 10, 64) 332 332 + if err != nil { 333 333 + return nil, fmt.Errorf("invalid GOLOG_ROTATE_KEEP value: %w", err) 334 334 + } 335 335 + keepOldUnset = false 336 336 + options.KeepOld = int(keepOld) 337 337 + } 338 338 + if keepOldUnset { 339 339 + options.KeepOld = 2 340 340 + } 341 341 + } 342 342 + var out io.Writer 343 343 + if (options.LogPath == "") || (options.LogPath == "-") { 344 344 + out = os.Stdout 345 345 + } else if options.LogRotateBytes != 0 { 346 346 + out = &logRotateWriter{ 347 347 + rotateBytes: options.LogRotateBytes, 348 348 + outPathTemplate: options.LogPath, 349 349 + keep: options.KeepOld, 350 350 + } 351 351 + } else { 352 352 + var err error 353 353 + out, err = os.Create(options.LogPath) 354 354 + if err != nil { 355 355 + return nil, fmt.Errorf("%s: %w", options.LogPath, err) 356 356 + } 357 357 + } 358 358 + var handler slog.Handler 359 359 + switch options.LogFormat { 360 360 + case "text": 361 361 + handler = slog.NewTextHandler(out, &hopts) 362 362 + case "json": 363 363 + handler = slog.NewJSONHandler(out, &hopts) 364 364 + default: 365 365 + return nil, fmt.Errorf("unknown log format: %#v", options.LogFormat) 366 366 + } 367 367 + logger := slog.New(handler) 368 368 + slog.SetDefault(logger) 369 369 + return logger, nil 370 370 + } 371 371 + 372 372 + type logRotateWriter struct { 373 373 + currentWriter io.WriteCloser 374 374 + 375 375 + // how much has been written to current log file 376 376 + currentBytes int64 377 377 + 378 378 + // e.g. path/to/logs/foo%T 379 379 + currentPath string 380 380 + 381 381 + // e.g. path/to/logs/current 382 382 + currentPathCurrent string 383 383 + 384 384 + rotateBytes int64 385 385 + 386 386 + outPathTemplate string 387 387 + 388 388 + // keep the most recent N log files (not including current) 389 389 + keep int 390 390 + } 391 391 + 392 392 + var currentMatcher = regexp.MustCompile("current_\\d+") 393 393 + 394 394 + func (w *logRotateWriter) cleanOldLogs() { 395 395 + if w.keep < 0 { 396 396 + // old log removal is disabled 397 397 + return 398 398 + } 399 399 + // w.currentPath was recently set as the new log 400 400 + dirpart, _ := filepath.Split(w.currentPath) 401 401 + // find old logs 402 402 + templateDirPart, templateNamePart := filepath.Split(w.outPathTemplate) 403 403 + if dirpart != templateDirPart { 404 404 + fmt.Fprintf(os.Stderr, "current dir part %#v != template dir part %#v\n", w.currentPath, w.outPathTemplate) 405 405 + return 406 406 + } 407 407 + // build a regexp that is string literal parts with \d+ replacing the UnixMilli part 408 408 + templateNameParts := strings.Split(templateNamePart, "%T") 409 409 + var sb strings.Builder 410 410 + first := true 411 411 + for _, part := range templateNameParts { 412 412 + if first { 413 413 + first = false 414 414 + } else { 415 415 + sb.WriteString("\\d+") 416 416 + } 417 417 + sb.WriteString(regexp.QuoteMeta(part)) 418 418 + } 419 419 + tmre, err := regexp.Compile(sb.String()) 420 420 + if err != nil { 421 421 + fmt.Fprintf(os.Stderr, "failed to compile old log template regexp: %#v\n", err) 422 422 + return 423 423 + } 424 424 + dir, err := os.ReadDir(dirpart) 425 425 + if err != nil { 426 426 + fmt.Fprintf(os.Stderr, "failed to read old log template dir: %#v\n", err) 427 427 + return 428 428 + } 429 429 + var found []fs.FileInfo 430 430 + for _, ent := range dir { 431 431 + name := ent.Name() 432 432 + if tmre.MatchString(name) || currentMatcher.MatchString(name) { 433 433 + fi, err := ent.Info() 434 434 + if err != nil { 435 435 + continue 436 436 + } 437 437 + found = append(found, fi) 438 438 + } 439 439 + } 440 440 + if len(found) <= w.keep { 441 441 + // not too many, nothing to do 442 442 + return 443 443 + } 444 444 + foundMtimeLess := func(i, j int) bool { 445 445 + return found[i].ModTime().Before(found[j].ModTime()) 446 446 + } 447 447 + sort.Slice(found, foundMtimeLess) 448 448 + drops := found[:len(found)-w.keep] 449 449 + for _, fi := range drops { 450 450 + fullpath := filepath.Join(dirpart, fi.Name()) 451 451 + err = os.Remove(fullpath) 452 452 + if err != nil { 453 453 + fmt.Fprintf(os.Stderr, "failed to rm old log: %#v\n", err) 454 454 + // but keep going 455 455 + } 456 456 + // maybe it would be safe to debug-log old log removal from within the logging infrastructure? 457 457 + } 458 458 + } 459 459 + 460 460 + func (w *logRotateWriter) closeOldLog() []error { 461 461 + if w.currentWriter == nil { 462 462 + return nil 463 463 + } 464 464 + var earlyWeakErrors []error 465 465 + err := w.currentWriter.Close() 466 466 + if err != nil { 467 467 + earlyWeakErrors = append(earlyWeakErrors, err) 468 468 + } 469 469 + w.currentWriter = nil 470 470 + w.currentBytes = 0 471 471 + w.currentPath = "" 472 472 + if w.currentPathCurrent != "" { 473 473 + err = os.Remove(w.currentPathCurrent) // not really an error until something else goes wrong 474 474 + if err != nil { 475 475 + earlyWeakErrors = append(earlyWeakErrors, err) 476 476 + } 477 477 + w.currentPathCurrent = "" 478 478 + } 479 479 + return earlyWeakErrors 480 480 + } 481 481 + 482 482 + func (w *logRotateWriter) openNewLog(earlyWeakErrors []error) (badErr error, weakErrors []error) { 483 483 + nowMillis := time.Now().UnixMilli() 484 484 + nows := strconv.FormatInt(nowMillis, 10) 485 485 + w.currentPath = strings.Replace(w.outPathTemplate, "%T", nows, -1) 486 486 + var err error 487 487 + w.currentWriter, err = os.Create(w.currentPath) 488 488 + if err != nil { 489 489 + earlyWeakErrors = append(earlyWeakErrors, err) 490 490 + return errors.Join(earlyWeakErrors...), nil 491 491 + } 492 492 + w.cleanOldLogs() 493 493 + dirpart, _ := filepath.Split(w.currentPath) 494 494 + if dirpart != "" { 495 495 + w.currentPathCurrent = filepath.Join(dirpart, "current") 496 496 + fi, err := os.Stat(w.currentPathCurrent) 497 497 + if err == nil && fi.Mode().IsRegular() { 498 498 + // move aside unknown "current" from a previous run 499 499 + // see also currentMatcher regexp current_\d+ 500 500 + err = os.Rename(w.currentPathCurrent, w.currentPathCurrent+"_"+nows) 501 501 + if err != nil { 502 502 + // not crucial if we can't move aside "current" 503 503 + // TODO: log warning ... but not from inside log writer? 504 504 + earlyWeakErrors = append(earlyWeakErrors, err) 505 505 + } 506 506 + } 507 507 + err = os.Link(w.currentPath, w.currentPathCurrent) 508 508 + if err != nil { 509 509 + // not crucial if we can't make "current" link 510 510 + // TODO: log warning ... but not from inside log writer? 511 511 + earlyWeakErrors = append(earlyWeakErrors, err) 512 512 + } 513 513 + } 514 514 + return nil, earlyWeakErrors 515 515 + } 516 516 + 517 517 + func (w *logRotateWriter) Write(p []byte) (n int, err error) { 518 518 + var earlyWeakErrors []error 519 519 + if int64(len(p))+w.currentBytes > w.rotateBytes { 520 520 + // next write would be over the limit 521 521 + earlyWeakErrors = w.closeOldLog() 522 522 + } 523 523 + if w.currentWriter == nil { 524 524 + // start new log file 525 525 + var err error 526 526 + err, earlyWeakErrors = w.openNewLog(earlyWeakErrors) 527 527 + if err != nil { 528 528 + return 0, err 529 529 + } 530 530 + } 531 531 + var wrote int 532 532 + wrote, err = w.currentWriter.Write(p) 533 533 + w.currentBytes += int64(wrote) 534 534 + if err != nil { 535 535 + earlyWeakErrors = append(earlyWeakErrors, err) 536 536 + return wrote, errors.Join(earlyWeakErrors...) 537 537 + } 538 538 + return wrote, nil 539 539 + }