From 076bce8727d3f02cc3cbf6cdfb560a758185aaf3 Mon Sep 17 00:00:00 2001 From: "Jason A. Donenfeld" Date: Wed, 20 Mar 2019 02:18:05 -0600 Subject: ringlogger: introduce basic file ring logging Signed-off-by: Jason A. Donenfeld --- ringlogger/cli_test.go | 80 +++++++++++++++ ringlogger/global.go | 31 ++++++ ringlogger/ringlogger_windows.go | 207 +++++++++++++++++++++++++++++++++++++++ 3 files changed, 318 insertions(+) create mode 100644 ringlogger/cli_test.go create mode 100644 ringlogger/global.go create mode 100644 ringlogger/ringlogger_windows.go (limited to 'ringlogger') diff --git a/ringlogger/cli_test.go b/ringlogger/cli_test.go new file mode 100644 index 00000000..64057b34 --- /dev/null +++ b/ringlogger/cli_test.go @@ -0,0 +1,80 @@ +/* SPDX-License-Identifier: MIT + * + * Copyright (C) 2019 WireGuard LLC. All Rights Reserved. + */ + +package ringlogger + +import ( + "fmt" + "os" + "sync" + "testing" + "time" +) + +func TestThreads(t *testing.T) { + wg := sync.WaitGroup{} + wg.Add(2) + go func() { + rl, err := NewRinglogger("ringlogger_test.bin", "ONE") + if err != nil { + t.Fatal(err) + } + for i := 0; i < 1024; i++ { + fmt.Fprintf(rl, "bla bla bla %d", i) + } + rl.Close() + wg.Done() + }() + go func() { + rl, err := NewRinglogger("ringlogger_test.bin", "TWO") + if err != nil { + t.Fatal(err) + } + for i := 1024; i < 2047; i++ { + fmt.Fprintf(rl, "bla bla bla %d", i) + } + rl.Close() + wg.Done() + }() + wg.Wait() +} + +func TestWriteText(t *testing.T) { + rl, err := NewRinglogger("ringlogger_test.bin", "TXT") + if err != nil { + t.Fatal(err) + } + if len(os.Args) != 3 { + t.Fatal("Should pass exactly one argument") + } + fmt.Fprintf(rl, os.Args[2]) + rl.Close() +} + +func TestDump(t *testing.T) { + rl, err := NewRinglogger("ringlogger_test.bin", "DMP") + if err != nil { + t.Fatal(err) + } + _, err = rl.WriteTo(os.Stdout) + if err != nil { + t.Fatal(err) + } + rl.Close() +} + +func TestFollow(t *testing.T) { + rl, err := NewRinglogger("ringlogger_test.bin", "FOL") + if err != nil { + t.Fatal(err) + } + cursor := CursorAll + for { + cursor = rl.FollowFromCursor(cursor, func(line string, stamp time.Time) { + fmt.Printf("%v: %s\n", stamp, line) + }) + time.Sleep(300 * time.Millisecond) + } +} diff --git a/ringlogger/global.go b/ringlogger/global.go new file mode 100644 index 00000000..da79b6de --- /dev/null +++ b/ringlogger/global.go @@ -0,0 +1,31 @@ +/* SPDX-License-Identifier: MIT + * + * Copyright (C) 2019 WireGuard LLC. All Rights Reserved. + */ + +package ringlogger + +import ( + "golang.zx2c4.com/wireguard/windows/conf" + "log" + "path" +) + +var Global *Ringlogger + +func InitGlobalLogger(tag string) error { + if Global != nil { + return nil + } + root, err := conf.RootDirectory() + if err != nil { + return err + } + Global, err = NewRinglogger(path.Join(root, "log.bin"), tag) + if err != nil { + return err + } + log.SetOutput(Global) + log.SetFlags(0) + return nil +} diff --git a/ringlogger/ringlogger_windows.go b/ringlogger/ringlogger_windows.go new file mode 100644 index 00000000..1a49570c --- /dev/null +++ b/ringlogger/ringlogger_windows.go @@ -0,0 +1,207 @@ +/* SPDX-License-Identifier: MIT + * + * Copyright (C) 2019 WireGuard LLC. All Rights Reserved. + */ + +package ringlogger + +import ( + "bytes" + "fmt" + "golang.org/x/sys/windows" + "io" + "os" + "runtime" + "sync/atomic" + "time" + "unsafe" +) + +const ( + maxLogLineLength = 512 + maxLines = 2048 + magic = 0xbadbabe +) + +type logLine struct { + timeNs int64 + line [maxLogLineLength]byte +} + +type logMem struct { + nextIndex uint32 + lines [maxLines]logLine + magic uint32 +} + +type Ringlogger struct { + tag string + file *os.File + mapping windows.Handle + log *logMem +} + +func NewRinglogger(filename string, tag string) (*Ringlogger, error) { + file, err := os.OpenFile(filename, os.O_RDWR|os.O_CREATE, 0600) + if err != nil { + return nil, err + } + err = file.Truncate(int64(unsafe.Sizeof(logMem{}))) + if err != nil { + return nil, err + } + mapping, err := windows.CreateFileMapping(windows.Handle(file.Fd()), nil, windows.PAGE_READWRITE, 0, 0, nil) + if err != nil { + return nil, err + } + view, err := windows.MapViewOfFile(mapping, windows.FILE_MAP_WRITE, 0, 0, 0) + if err != nil { + return nil, err + } + if err != nil { + windows.CloseHandle(mapping) + return nil, err + } + log := (*logMem)(unsafe.Pointer(view)) + if log.magic != magic { + bytes := (*[unsafe.Sizeof(logMem{})]byte)(unsafe.Pointer(log)) + for i := range bytes { + bytes[i] = 0 + } + log.magic = magic + windows.FlushViewOfFile(view, uintptr(len(bytes))) + } + + rl := &Ringlogger{ + tag: tag, + file: file, + mapping: mapping, + log: log, + } + runtime.SetFinalizer(rl, (*Ringlogger).Close) + return rl, nil +} + +func (rl *Ringlogger) Write(p []byte) (n int, err error) { + // Race: This isn't synchronized with the fetch_add below, so items might be slightly out of order. + ts := time.Now().UnixNano() + + if rl.log == nil { + return 0, io.EOF + } + + // Race: More than maxLines writers and this will clash. + index := atomic.AddUint32(&rl.log.nextIndex, 1) - 1 + line := &rl.log.lines[index%maxLines] + + // Race: Before this line executes, we'll display old data after new data. + atomic.StoreInt64(&line.timeNs, 0) + for i := range line.line { + line.line[i] = 0 + } + + text := []byte(fmt.Sprintf("[%s] %s", rl.tag, bytes.TrimSpace(p))) + if len(text) > maxLogLineLength-1 { + text = text[:maxLogLineLength-1] + } + line.line[len(text)] = 0 + copy(line.line[:], text[:]) + atomic.StoreInt64(&line.timeNs, ts) + + windows.FlushViewOfFile((uintptr)(unsafe.Pointer(&rl.log.nextIndex)), unsafe.Sizeof(rl.log.nextIndex)) + windows.FlushViewOfFile((uintptr)(unsafe.Pointer(line)), unsafe.Sizeof(*line)) + + return len(p), nil +} + +func (rl *Ringlogger) WriteTo(out io.Writer) (n int64, err error) { + if rl.log == nil { + return 0, io.EOF + } + log := *rl.log + i := log.nextIndex + for l := 0; l < maxLines; l++ { + line := &log.lines[i%maxLines] + if line.timeNs == 0 { + i++ + continue + } + index := bytes.IndexByte(line.line[:], 0) + if index < 1 { + i++ + continue + } + var bytes int + bytes, err = fmt.Fprintf(out, "%s: %s\n", time.Unix(0, line.timeNs).Format("2006-01-02 15:04:05.000000"), line.line[:index]) + if err != nil { + return + } + n += int64(bytes) + i++ + } + return +} + +const CursorAll = ^uint32(0) + +type FollowLine struct { + Line string + Stamp time.Time +} + +func (rl *Ringlogger) FollowFromCursor(cursor uint32) ([]FollowLine, uint32) { + followLines := make([]FollowLine, 0, maxLines) + + if rl.log == nil { + return followLines, cursor + } + + log := *rl.log + i := cursor + + if i == CursorAll { + i = log.nextIndex + } + + for l := 0; l < maxLines; l++ { + line := &log.lines[i%maxLines] + if cursor != CursorAll && i%maxLines == log.nextIndex%maxLines { + break + } + if line.timeNs == 0 { + if cursor == CursorAll { + i++ + continue + } else { + break + } + } + index := bytes.IndexByte(line.line[:], 0) + if index > 0 { + followLines = append(followLines, FollowLine{string(line.line[:index]), time.Unix(0, line.timeNs)}) + } + i++ + cursor = i % maxLines + } + return followLines, cursor +} + +func (rl *Ringlogger) Close() error { + if rl.file != nil { + rl.file.Close() + rl.file = nil + } + if rl.log != nil { + windows.UnmapViewOfFile((uintptr)(unsafe.Pointer(rl.log))) + rl.log = nil + } + if rl.mapping != 0 { + windows.CloseHandle(rl.mapping) + rl.mapping = 0 + } + return nil +} + +func (rl *Ringlogger) Filename() string { + return rl.file.Name() +} -- cgit v1.2.3-59-g8ed1b