diff --git a/pkg/components/renderer/renderer.go b/pkg/components/renderer/renderer.go index 25d77557342..313f7892707 100644 --- a/pkg/components/renderer/renderer.go +++ b/pkg/components/renderer/renderer.go @@ -91,9 +91,15 @@ func RenderToPng(params *RenderOpts) (string, error) { timeout = 15 } + phantomDebugArg := "--debug=false" + if log.GetLogLevelFor("png-renderer") >= log.LvlDebug { + phantomDebugArg = "--debug=true" + } + cmdArgs := []string{ "--ignore-ssl-errors=true", "--web-security=false", + phantomDebugArg, scriptPath, "url=" + url, "width=" + params.Width, @@ -109,15 +115,13 @@ func RenderToPng(params *RenderOpts) (string, error) { } cmd := exec.Command(binPath, cmdArgs...) - stdout, err := cmd.StdoutPipe() + output, err := cmd.StdoutPipe() if err != nil { + rendererLog.Error("Could not acquire stdout pipe", err) return "", err } - stderr, err := cmd.StderrPipe() - if err != nil { - return "", err - } + cmd.Stderr = cmd.Stdout if params.Timezone != "" { baseEnviron := os.Environ() @@ -126,11 +130,12 @@ func RenderToPng(params *RenderOpts) (string, error) { err = cmd.Start() if err != nil { + rendererLog.Error("Could not start command", err) return "", err } - go io.Copy(os.Stdout, stdout) - go io.Copy(os.Stdout, stderr) + logWriter := log.NewLogWriter(rendererLog, log.LvlDebug, "[phantom] ") + go io.Copy(logWriter, output) done := make(chan error) go func() { diff --git a/pkg/log/log.go b/pkg/log/log.go index 88b90f0cf8e..0e6874e1b4b 100644 --- a/pkg/log/log.go +++ b/pkg/log/log.go @@ -21,6 +21,7 @@ import ( var Root log15.Logger var loggersToClose []DisposableHandler +var filters map[string]log15.Lvl func init() { loggersToClose = make([]DisposableHandler, 0) @@ -114,6 +115,25 @@ func Close() { loggersToClose = make([]DisposableHandler, 0) } +func GetLogLevelFor(name string) Lvl { + if level, ok := filters[name]; ok { + switch level { + case log15.LvlWarn: + return LvlWarn + case log15.LvlInfo: + return LvlInfo + case log15.LvlError: + return LvlError + case log15.LvlCrit: + return LvlCrit + default: + return LvlDebug + } + } + + return LvlInfo +} + var logLevels = map[string]log15.Lvl{ "trace": log15.LvlDebug, "debug": log15.LvlDebug, @@ -187,7 +207,7 @@ func ReadLoggingConfig(modes []string, logsPath string, cfg *ini.File) { // Log level. _, level := getLogLevelFromConfig("log."+mode, defaultLevelName, cfg) - modeFilters := getFilters(util.SplitString(sec.Key("filters").String())) + filters := getFilters(util.SplitString(sec.Key("filters").String())) format := getLogFormat(sec.Key("format").MustString("")) var handler log15.Handler @@ -219,12 +239,12 @@ func ReadLoggingConfig(modes []string, logsPath string, cfg *ini.File) { } for key, value := range defaultFilters { - if _, exist := modeFilters[key]; !exist { - modeFilters[key] = value + if _, exist := filters[key]; !exist { + filters[key] = value } } - handler = LogFilterHandler(level, modeFilters, handler) + handler = LogFilterHandler(level, filters, handler) handlers = append(handlers, handler) } diff --git a/pkg/log/log_writer.go b/pkg/log/log_writer.go new file mode 100644 index 00000000000..2ff401a7f0a --- /dev/null +++ b/pkg/log/log_writer.go @@ -0,0 +1,39 @@ +package log + +import ( + "io" + "strings" +) + +type logWriterImpl struct { + log Logger + level Lvl + prefix string +} + +func NewLogWriter(log Logger, level Lvl, prefix string) io.Writer { + return &logWriterImpl{ + log: log, + level: level, + prefix: prefix, + } +} + +func (l *logWriterImpl) Write(p []byte) (n int, err error) { + message := l.prefix + strings.TrimSpace(string(p)) + + switch l.level { + case LvlCrit: + l.log.Crit(message) + case LvlError: + l.log.Error(message) + case LvlWarn: + l.log.Warn(message) + case LvlInfo: + l.log.Info(message) + default: + l.log.Debug(message) + } + + return len(p), nil +} diff --git a/pkg/log/log_writer_test.go b/pkg/log/log_writer_test.go new file mode 100644 index 00000000000..4537b4d6100 --- /dev/null +++ b/pkg/log/log_writer_test.go @@ -0,0 +1,116 @@ +package log + +import ( + "testing" + + "github.com/inconshreveable/log15" + . "github.com/smartystreets/goconvey/convey" +) + +type FakeLogger struct { + debug string + info string + warn string + err string + crit string +} + +func (f *FakeLogger) New(ctx ...interface{}) log15.Logger { + return nil +} + +func (f *FakeLogger) Debug(msg string, ctx ...interface{}) { + f.debug = msg +} + +func (f *FakeLogger) Info(msg string, ctx ...interface{}) { + f.info = msg +} + +func (f *FakeLogger) Warn(msg string, ctx ...interface{}) { + f.warn = msg +} + +func (f *FakeLogger) Error(msg string, ctx ...interface{}) { + f.err = msg +} + +func (f *FakeLogger) Crit(msg string, ctx ...interface{}) { + f.crit = msg +} + +func (f *FakeLogger) GetHandler() log15.Handler { + return nil +} + +func (f *FakeLogger) SetHandler(l log15.Handler) {} + +func TestLogWriter(t *testing.T) { + Convey("When writing to a LogWriter", t, func() { + Convey("Should write using the correct level [crit]", func() { + fake := &FakeLogger{} + + crit := NewLogWriter(fake, LvlCrit, "") + n, err := crit.Write([]byte("crit")) + + So(n, ShouldEqual, 4) + So(err, ShouldBeNil) + So(fake.crit, ShouldEqual, "crit") + }) + + Convey("Should write using the correct level [error]", func() { + fake := &FakeLogger{} + + crit := NewLogWriter(fake, LvlError, "") + n, err := crit.Write([]byte("error")) + + So(n, ShouldEqual, 5) + So(err, ShouldBeNil) + So(fake.err, ShouldEqual, "error") + }) + + Convey("Should write using the correct level [warn]", func() { + fake := &FakeLogger{} + + crit := NewLogWriter(fake, LvlWarn, "") + n, err := crit.Write([]byte("warn")) + + So(n, ShouldEqual, 4) + So(err, ShouldBeNil) + So(fake.warn, ShouldEqual, "warn") + }) + + Convey("Should write using the correct level [info]", func() { + fake := &FakeLogger{} + + crit := NewLogWriter(fake, LvlInfo, "") + n, err := crit.Write([]byte("info")) + + So(n, ShouldEqual, 4) + So(err, ShouldBeNil) + So(fake.info, ShouldEqual, "info") + }) + + Convey("Should write using the correct level [debug]", func() { + fake := &FakeLogger{} + + crit := NewLogWriter(fake, LvlDebug, "") + n, err := crit.Write([]byte("debug")) + + So(n, ShouldEqual, 5) + So(err, ShouldBeNil) + So(fake.debug, ShouldEqual, "debug") + }) + + Convey("Should prefix the output with the prefix", func() { + fake := &FakeLogger{} + + crit := NewLogWriter(fake, LvlDebug, "prefix") + n, err := crit.Write([]byte("debug")) + + So(n, ShouldEqual, 5) // n is how much of input consumed + So(err, ShouldBeNil) + So(fake.debug, ShouldEqual, "prefixdebug") + }) + }) +}