Merge pull request #1741 from calmh/verbose

Verbose logging
This commit is contained in:
Audrius Butkevicius 2015-04-30 21:54:49 +01:00
commit 3c50b3a9e0
4 changed files with 152 additions and 1 deletions

2
Godeps/Godeps.json generated
View File

@ -11,7 +11,7 @@
}, },
{ {
"ImportPath": "github.com/calmh/logger", "ImportPath": "github.com/calmh/logger",
"Rev": "f50d32b313bec2933a3e1049f7416a29f3413d29" "Rev": "4d4e2801954c5581e4c2a80a3d3beb3b3645fd04"
}, },
{ {
"ImportPath": "github.com/calmh/luhn", "ImportPath": "github.com/calmh/luhn",

View File

@ -16,6 +16,7 @@ type LogLevel int
const ( const (
LevelDebug LogLevel = iota LevelDebug LogLevel = iota
LevelVerbose
LevelInfo LevelInfo
LevelOK LevelOK
LevelWarn LevelWarn
@ -83,6 +84,24 @@ func (l *Logger) Debugf(format string, vals ...interface{}) {
l.callHandlers(LevelDebug, s) l.callHandlers(LevelDebug, s)
} }
// Infoln logs a line with a VERBOSE prefix.
func (l *Logger) Verboseln(vals ...interface{}) {
l.mut.Lock()
defer l.mut.Unlock()
s := fmt.Sprintln(vals...)
l.logger.Output(2, "VERBOSE: "+s)
l.callHandlers(LevelVerbose, s)
}
// Infof logs a formatted line with a VERBOSE prefix.
func (l *Logger) Verbosef(format string, vals ...interface{}) {
l.mut.Lock()
defer l.mut.Unlock()
s := fmt.Sprintf(format, vals...)
l.logger.Output(2, "VERBOSE: "+s)
l.callHandlers(LevelVerbose, s)
}
// Infoln logs a line with an INFO prefix. // Infoln logs a line with an INFO prefix.
func (l *Logger) Infoln(vals ...interface{}) { func (l *Logger) Infoln(vals ...interface{}) {
l.mut.Lock() l.mut.Lock()

View File

@ -194,6 +194,7 @@ var (
generateDir string generateDir string
logFile string logFile string
auditEnabled bool auditEnabled bool
verbose bool
noRestart = os.Getenv("STNORESTART") != "" noRestart = os.Getenv("STNORESTART") != ""
noUpgrade = os.Getenv("STNOUPGRADE") != "" noUpgrade = os.Getenv("STNOUPGRADE") != ""
guiAddress = os.Getenv("STGUIADDRESS") // legacy guiAddress = os.Getenv("STGUIADDRESS") // legacy
@ -231,6 +232,7 @@ func main() {
flag.BoolVar(&showVersion, "version", false, "Show version") flag.BoolVar(&showVersion, "version", false, "Show version")
flag.StringVar(&upgradeTo, "upgrade-to", upgradeTo, "Force upgrade directly from specified URL") flag.StringVar(&upgradeTo, "upgrade-to", upgradeTo, "Force upgrade directly from specified URL")
flag.BoolVar(&auditEnabled, "audit", false, "Write events to audit file") flag.BoolVar(&auditEnabled, "audit", false, "Write events to audit file")
flag.BoolVar(&verbose, "verbose", false, "Print verbose log output")
flag.Usage = usageFor(flag.CommandLine, usage, fmt.Sprintf(extraUsage, baseDirs["config"])) flag.Usage = usageFor(flag.CommandLine, usage, fmt.Sprintf(extraUsage, baseDirs["config"]))
flag.Parse() flag.Parse()
@ -391,6 +393,10 @@ func syncthingMain() {
startAuditing(mainSvc) startAuditing(mainSvc)
} }
if verbose {
mainSvc.Add(newVerboseSvc())
}
if len(os.Getenv("GOMAXPROCS")) == 0 { if len(os.Getenv("GOMAXPROCS")) == 0 {
runtime.GOMAXPROCS(runtime.NumCPU()) runtime.GOMAXPROCS(runtime.NumCPU())
} }

126
cmd/syncthing/verbose.go Normal file
View File

@ -0,0 +1,126 @@
// 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 (
"fmt"
"github.com/syncthing/syncthing/internal/events"
)
// The verbose logging service subscribes to events and prints these in
// verbose format to the console using INFO level.
type verboseSvc struct {
stop chan struct{} // signals time to stop
started chan struct{} // signals startup complete
}
func newVerboseSvc() *verboseSvc {
return &verboseSvc{
stop: make(chan struct{}),
started: make(chan struct{}),
}
}
// Serve runs the verbose logging service.
func (s *verboseSvc) Serve() {
sub := events.Default.Subscribe(events.AllEvents)
defer events.Default.Unsubscribe(sub)
// We're ready to start processing events.
close(s.started)
for {
select {
case ev := <-sub.C():
formatted := s.formatEvent(ev)
if formatted != "" {
l.Verboseln(formatted)
}
case <-s.stop:
return
}
}
}
// Stop stops the verbose logging service.
func (s *verboseSvc) Stop() {
close(s.stop)
}
// WaitForStart returns once the verbose logging service is ready to receive
// events, or immediately if it's already running.
func (s *verboseSvc) WaitForStart() {
<-s.started
}
func (s *verboseSvc) formatEvent(ev events.Event) string {
switch ev.Type {
case events.Ping, events.DownloadProgress:
// Skip
return ""
case events.Starting:
return fmt.Sprintf("Starting up (%s)", ev.Data.(map[string]string)["home"])
case events.StartupComplete:
return "Startup complete"
case events.DeviceDiscovered:
data := ev.Data.(map[string]interface{})
return fmt.Sprintf("Discovered device %v at %v", data["device"], data["addrs"])
case events.DeviceConnected:
data := ev.Data.(map[string]string)
return fmt.Sprintf("Connected to device %v at %v", data["id"], data["addr"])
case events.DeviceDisconnected:
data := ev.Data.(map[string]string)
return fmt.Sprintf("Disconnected from device %v", data["id"])
case events.StateChanged:
data := ev.Data.(map[string]interface{})
return fmt.Sprintf("Folder %q is now %v", data["folder"], data["to"])
case events.RemoteIndexUpdated:
data := ev.Data.(map[string]interface{})
return fmt.Sprintf("Device %v sent an index update for %q with %d items", data["device"], data["folder"], data["items"])
case events.LocalIndexUpdated:
data := ev.Data.(map[string]interface{})
return fmt.Sprintf("Updated index for folder %q with %v items", data["folder"], data["items"])
case events.DeviceRejected:
data := ev.Data.(map[string]interface{})
return fmt.Sprintf("Rejected connection from device %v at %v", data["device"], data["address"])
case events.FolderRejected:
data := ev.Data.(map[string]string)
return fmt.Sprintf("Rejected unshared folder %q from device %v", data["folder"], data["device"])
case events.ItemStarted:
data := ev.Data.(map[string]interface{})
return fmt.Sprintf("Started syncing %q / %q (%v %v)", data["folder"], data["item"], data["action"], data["type"])
case events.ItemFinished:
data := ev.Data.(map[string]interface{})
if err := data["err"]; err != nil {
return fmt.Sprintf("Finished syncing %q / %q (%v %v): %v", data["folder"], data["item"], data["action"], data["type"], err)
}
return fmt.Sprintf("Finished syncing %q / %q (%v %v): Success", data["folder"], data["item"], data["action"], data["type"])
case events.ConfigSaved:
return "Configuration was saved"
case events.FolderCompletion:
data := ev.Data.(map[string]interface{})
return fmt.Sprintf("Completion for folder %q on device %v is %v%%", data["folder"], data["device"], data["completion"])
case events.FolderSummary:
data := ev.Data.(map[string]interface{})
sum := data["summary"].(map[string]interface{})
delete(sum, "invalid")
delete(sum, "ignorePatterns")
delete(sum, "stateChanged")
return fmt.Sprintf("Summary for folder %q is %v", data["folder"], data["summary"])
}
return fmt.Sprintf("%s %#v", ev.Type, ev)
}