From 131f2be8571ec1655f2d6fad073e0762fa770e5b Mon Sep 17 00:00:00 2001 From: Jakob Borg Date: Sat, 25 Apr 2015 18:21:47 +0900 Subject: [PATCH] Add audit log feature --- cmd/syncthing/audit.go | 69 ++++++++++++++++++++++++++++++++++ cmd/syncthing/auditsvc_test.go | 54 ++++++++++++++++++++++++++ cmd/syncthing/locations.go | 16 +++++++- cmd/syncthing/main.go | 28 ++++++++++++++ cmd/syncthing/monitor.go | 2 +- test/.gitignore | 3 ++ 6 files changed, 170 insertions(+), 2 deletions(-) create mode 100644 cmd/syncthing/audit.go create mode 100644 cmd/syncthing/auditsvc_test.go diff --git a/cmd/syncthing/audit.go b/cmd/syncthing/audit.go new file mode 100644 index 000000000..1bfe0715c --- /dev/null +++ b/cmd/syncthing/audit.go @@ -0,0 +1,69 @@ +// Copyright (C) 2015 The Syncthing Authors. +// +// This Source Code Form is subject to the terms of the Mozilla Public +// License, v. 2.0. If a copy of the MPL was not distributed with this file, +// You can obtain one at http://mozilla.org/MPL/2.0/. + +package main + +import ( + "encoding/json" + "io" + + "github.com/syncthing/syncthing/internal/events" +) + +// The auditSvc subscribes to events and writes these in JSON format, one +// event per line, to the specified writer. +type auditSvc struct { + w io.Writer // audit destination + stop chan struct{} // signals time to stop + started chan struct{} // signals startup complete + stopped chan struct{} // signals stop complete +} + +func newAuditSvc(w io.Writer) *auditSvc { + return &auditSvc{ + w: w, + stop: make(chan struct{}), + started: make(chan struct{}), + stopped: make(chan struct{}), + } +} + +// Serve runs the audit service. +func (s *auditSvc) Serve() { + defer close(s.stopped) + sub := events.Default.Subscribe(events.AllEvents) + defer events.Default.Unsubscribe(sub) + enc := json.NewEncoder(s.w) + + // We're ready to start processing events. + close(s.started) + + for { + select { + case ev := <-sub.C(): + enc.Encode(ev) + case <-s.stop: + return + } + } +} + +// Stop stops the audit service. +func (s *auditSvc) Stop() { + close(s.stop) +} + +// WaitForStart returns once the audit service is ready to receive events, or +// immediately if it's already running. +func (s *auditSvc) WaitForStart() { + <-s.started +} + +// WaitForStop returns once the audit service has stopped. +// (Needed by the tests.) +func (s *auditSvc) WaitForStop() { + <-s.stopped +} diff --git a/cmd/syncthing/auditsvc_test.go b/cmd/syncthing/auditsvc_test.go new file mode 100644 index 000000000..42b853e7a --- /dev/null +++ b/cmd/syncthing/auditsvc_test.go @@ -0,0 +1,54 @@ +// Copyright (C) 2015 The Syncthing Authors. +// +// This Source Code Form is subject to the terms of the Mozilla Public +// License, v. 2.0. If a copy of the MPL was not distributed with this file, +// You can obtain one at http://mozilla.org/MPL/2.0/. + +package main + +import ( + "bytes" + "strings" + "testing" + "time" + + "github.com/syncthing/syncthing/internal/events" +) + +func TestAuditService(t *testing.T) { + buf := new(bytes.Buffer) + svc := newAuditSvc(buf) + + // Event sent before start, will not be logged + events.Default.Log(events.Ping, "the first event") + + go svc.Serve() + svc.WaitForStart() + + // Event that should end up in the audit log + events.Default.Log(events.Ping, "the second event") + + // We need to give the events time to arrive, since the channels are buffered etc. + time.Sleep(10 * time.Millisecond) + + svc.Stop() + svc.WaitForStop() + + // This event should not be logged, since we have stopped. + events.Default.Log(events.Ping, "the third event") + + result := string(buf.Bytes()) + t.Log(result) + + if strings.Contains(result, "first event") { + t.Error("Unexpected first event") + } + + if !strings.Contains(result, "second event") { + t.Error("Missing second event") + } + + if strings.Contains(result, "third event") { + t.Error("Missing third event") + } +} diff --git a/cmd/syncthing/locations.go b/cmd/syncthing/locations.go index b90273045..f2856267f 100644 --- a/cmd/syncthing/locations.go +++ b/cmd/syncthing/locations.go @@ -11,6 +11,7 @@ import ( "path/filepath" "runtime" "strings" + "time" "github.com/syncthing/syncthing/internal/osutil" ) @@ -29,6 +30,7 @@ const ( locLogFile = "logFile" locCsrfTokens = "csrfTokens" locPanicLog = "panicLog" + locAuditLog = "auditLog" locDefFolder = "defFolder" ) @@ -48,7 +50,8 @@ var locations = map[locationEnum]string{ locDatabase: "${config}/index-v0.11.0.db", locLogFile: "${config}/syncthing.log", // -logfile on Windows locCsrfTokens: "${config}/csrftokens.txt", - locPanicLog: "${config}/panic-20060102-150405.log", // passed through time.Format() + locPanicLog: "${config}/panic-${timestamp}.log", + locAuditLog: "${config}/audit-${timestamp}.log", locDefFolder: "${home}/Sync", } @@ -107,3 +110,14 @@ func homeDir() string { } return home } + +func timestampedLoc(key locationEnum) string { + // We take the roundtrip via "${timestamp}" instead of passing the path + // directly through time.Format() to avoid issues when the path we are + // expanding contains numbers; otherwise for example + // /home/user2006/.../panic-20060102-150405.log would get both instances of + // 2006 replaced by 2015... + tpl := locations[key] + now := time.Now().Format("20060102-150405") + return strings.Replace(tpl, "${timestamp}", now, -1) +} diff --git a/cmd/syncthing/main.go b/cmd/syncthing/main.go index cfc37ad02..a953dbf85 100644 --- a/cmd/syncthing/main.go +++ b/cmd/syncthing/main.go @@ -196,6 +196,7 @@ var ( noConsole bool generateDir string logFile string + auditEnabled bool noRestart = os.Getenv("STNORESTART") != "" noUpgrade = os.Getenv("STNOUPGRADE") != "" guiAddress = os.Getenv("STGUIADDRESS") // legacy @@ -232,6 +233,7 @@ func main() { flag.BoolVar(&doUpgradeCheck, "upgrade-check", false, "Check for available upgrade") flag.BoolVar(&showVersion, "version", false, "Show version") flag.StringVar(&upgradeTo, "upgrade-to", upgradeTo, "Force upgrade directly from specified URL") + flag.BoolVar(&auditEnabled, "audit", false, "Write events to audit file") flag.Usage = usageFor(flag.CommandLine, usage, fmt.Sprintf(extraUsage, baseDirs["config"])) flag.Parse() @@ -384,6 +386,14 @@ func syncthingMain() { }) mainSvc.ServeBackground() + // Set a log prefix similar to the ID we will have later on, or early log + // lines look ugly. + l.SetPrefix("[start] ") + + if auditEnabled { + startAuditing(mainSvc) + } + if len(os.Getenv("GOMAXPROCS")) == 0 { runtime.GOMAXPROCS(runtime.NumCPU()) } @@ -654,6 +664,23 @@ func syncthingMain() { os.Exit(code) } +func startAuditing(mainSvc *suture.Supervisor) { + auditFile := timestampedLoc(locAuditLog) + fd, err := os.OpenFile(auditFile, os.O_WRONLY|os.O_CREATE|os.O_EXCL, 0600) + if err != nil { + l.Fatalln("Audit:", err) + } + + auditSvc := newAuditSvc(fd) + mainSvc.Add(auditSvc) + + // We wait for the audit service to fully start before we return, to + // ensure we capture all events from the start. + auditSvc.WaitForStart() + + l.Infoln("Audit log in", auditFile) +} + func setupGUI(cfg *config.Wrapper, m *model.Model) { opts := cfg.Options() guiCfg := overrideGUIConfig(cfg.GUI(), guiAddress, guiAuthentication, guiAPIKey) @@ -1023,6 +1050,7 @@ func autoUpgrade() { func cleanConfigDirectory() { patterns := map[string]time.Duration{ "panic-*.log": 7 * 24 * time.Hour, // keep panic logs for a week + "audit-*.log": 7 * 24 * time.Hour, // keep audit logs for a week "index": 14 * 24 * time.Hour, // keep old index format for two weeks "config.xml.v*": 30 * 24 * time.Hour, // old config versions for a month "*.idx.gz": 30 * 24 * time.Hour, // these should for sure no longer exist diff --git a/cmd/syncthing/monitor.go b/cmd/syncthing/monitor.go index df1e51379..59b4f4b78 100644 --- a/cmd/syncthing/monitor.go +++ b/cmd/syncthing/monitor.go @@ -163,7 +163,7 @@ func copyStderr(stderr io.ReadCloser, dst io.Writer) { dst.Write([]byte(line)) if strings.HasPrefix(line, "panic:") || strings.HasPrefix(line, "fatal error:") { - panicFd, err = os.Create(time.Now().Format(locations[locPanicLog])) + panicFd, err = os.Create(timestampedLoc(locPanicLog)) if err != nil { l.Warnln("Create panic log:", err) continue diff --git a/test/.gitignore b/test/.gitignore index 9dc35dcb6..8127f40cc 100644 --- a/test/.gitignore +++ b/test/.gitignore @@ -17,3 +17,6 @@ s4d http h*/index* *.syncthing-reset* +panic-*.log +audit-*.log +h*/config.xml.v*