diff --git a/cmd/dlv/cmds/commands.go b/cmd/dlv/cmds/commands.go index 38e92174..4cb77e4b 100644 --- a/cmd/dlv/cmds/commands.go +++ b/cmd/dlv/cmds/commands.go @@ -364,7 +364,7 @@ func traceCmd(cmd *cobra.Command, args []string) { APIVersion: 2, WorkingDir: WorkingDir, Backend: Backend, - }, logflags.RPC()) + }) if err := server.Run(); err != nil { fmt.Fprintln(os.Stderr, err) return 1 @@ -510,7 +510,7 @@ func execute(attachPid int, processArgs []string, conf *config.Config, coreFile Foreground: Headless, DisconnectChan: disconnectChan, - }, logflags.RPC()) + }) default: fmt.Printf("Unknown API version: %d\n", APIVersion) return 1 @@ -535,8 +535,6 @@ func execute(attachPid int, processArgs []string, conf *config.Config, coreFile var status int if Headless { - // Print listener address - fmt.Printf("API server listening at: %s\n", listener.Addr()) ch := make(chan os.Signal, 1) signal.Notify(ch, syscall.SIGINT) select { diff --git a/cmd/dlv/dlv_test.go b/cmd/dlv/dlv_test.go index e9710ecc..a50ce235 100644 --- a/cmd/dlv/dlv_test.go +++ b/cmd/dlv/dlv_test.go @@ -80,13 +80,13 @@ func TestBuild(t *testing.T) { buildtestdir := filepath.Join(fixtures, "buildtest") - cmd := exec.Command(dlvbin, "debug", "--headless=true", "--listen="+listenAddr, "--api-version=2", "--backend="+testBackend) + cmd := exec.Command(dlvbin, "debug", "--headless=true", "--listen="+listenAddr, "--api-version=2", "--backend="+testBackend, "--log", "--log-output=debugger,rpc") cmd.Dir = buildtestdir - stdout, err := cmd.StdoutPipe() - assertNoError(err, t, "stdout pipe") + stderr, err := cmd.StderrPipe() + assertNoError(err, t, "stderr pipe") cmd.Start() - scan := bufio.NewScanner(stdout) + scan := bufio.NewScanner(stderr) // wait for the debugger to start scan.Scan() go func() { diff --git a/pkg/dwarf/line/line_parser.go b/pkg/dwarf/line/line_parser.go index d4ece88c..a3749ee6 100644 --- a/pkg/dwarf/line/line_parser.go +++ b/pkg/dwarf/line/line_parser.go @@ -27,14 +27,13 @@ type DebugLineInfo struct { Instructions []byte Lookup map[string]*FileEntry + Logf func(string, ...interface{}) + // stateMachineCache[pc] is a state machine stopped at pc stateMachineCache map[uint64]*StateMachine // lastMachineCache[pc] is a state machine stopped at an address after pc lastMachineCache map[uint64]*StateMachine - - // logSuppressedErrors enables logging of otherwise suppressed errors - logSuppressedErrors bool } type FileEntry struct { @@ -47,7 +46,7 @@ type FileEntry struct { type DebugLines []*DebugLineInfo // ParseAll parses all debug_line segments found in data -func ParseAll(data []byte) DebugLines { +func ParseAll(data []byte, logfn func(string, ...interface{})) DebugLines { var ( lines = make(DebugLines, 0) buf = bytes.NewBuffer(data) @@ -55,7 +54,7 @@ func ParseAll(data []byte) DebugLines { // We have to parse multiple file name tables here. for buf.Len() > 0 { - lines = append(lines, Parse("", buf)) + lines = append(lines, Parse("", buf, logfn)) } return lines @@ -63,8 +62,9 @@ func ParseAll(data []byte) DebugLines { // Parse parses a single debug_line segment from buf. Compdir is the // DW_AT_comp_dir attribute of the associated compile unit. -func Parse(compdir string, buf *bytes.Buffer) *DebugLineInfo { +func Parse(compdir string, buf *bytes.Buffer, logfn func(string, ...interface{})) *DebugLineInfo { dbl := new(DebugLineInfo) + dbl.Logf = logfn dbl.Lookup = make(map[string]*FileEntry) if compdir != "" { dbl.IncludeDirs = append(dbl.IncludeDirs, compdir) @@ -146,8 +146,3 @@ func readFileEntry(info *DebugLineInfo, buf *bytes.Buffer, exitOnEmptyPath bool) return entry } - -// LogSuppressedErrors enables or disables logging of suppressed errors -func (dbl *DebugLineInfo) LogSuppressedErrors(v bool) { - dbl.logSuppressedErrors = v -} diff --git a/pkg/dwarf/line/line_parser_test.go b/pkg/dwarf/line/line_parser_test.go index d6d69cf3..9da512ab 100644 --- a/pkg/dwarf/line/line_parser_test.go +++ b/pkg/dwarf/line/line_parser_test.go @@ -67,7 +67,7 @@ const ( func testDebugLinePrologueParser(p string, t *testing.T) { data := grabDebugLineSection(p, t) - debugLines := ParseAll(data) + debugLines := ParseAll(data, nil) mainFileFound := false @@ -164,7 +164,7 @@ func BenchmarkLineParser(b *testing.B) { b.ResetTimer() for i := 0; i < b.N; i++ { - _ = ParseAll(data) + _ = ParseAll(data, nil) } } @@ -179,7 +179,7 @@ func loadBenchmarkData(tb testing.TB) DebugLines { tb.Fatal("Could not read test data", err) } - return ParseAll(data) + return ParseAll(data, nil) } func BenchmarkStateMachine(b *testing.B) { diff --git a/pkg/dwarf/line/state_machine.go b/pkg/dwarf/line/state_machine.go index 6192172c..27408860 100644 --- a/pkg/dwarf/line/state_machine.go +++ b/pkg/dwarf/line/state_machine.go @@ -5,7 +5,6 @@ import ( "encoding/binary" "errors" "fmt" - "log" "github.com/derekparker/delve/pkg/dwarf/util" ) @@ -125,8 +124,8 @@ func (lineInfo *DebugLineInfo) AllPCsForFileLine(f string, l int) (pcs []uint64) for { if err := sm.next(); err != nil { - if lineInfo.logSuppressedErrors { - log.Printf("AllPCsForFileLine error: %v", err) + if lineInfo.Logf != nil { + lineInfo.Logf("AllPCsForFileLine error: %v", err) } break } @@ -154,8 +153,8 @@ func (lineInfo *DebugLineInfo) AllPCsBetween(begin, end uint64, excludeFile stri for { if err := sm.next(); err != nil { - if lineInfo.logSuppressedErrors { - log.Printf("AllPCsBetween error: %v", err) + if lineInfo.Logf != nil { + lineInfo.Logf("AllPCsBetween error: %v", err) } break } @@ -228,8 +227,8 @@ func (lineInfo *DebugLineInfo) PCToLine(basePC, pc uint64) (string, int) { func (sm *StateMachine) PCToLine(pc uint64) (string, int, bool) { if !sm.started { if err := sm.next(); err != nil { - if sm.dbl.logSuppressedErrors { - log.Printf("PCToLine error: %v", err) + if sm.dbl.Logf != nil { + sm.dbl.Logf("PCToLine error: %v", err) } return "", 0, false } @@ -247,8 +246,8 @@ func (sm *StateMachine) PCToLine(pc uint64) (string, int, bool) { } } if err := sm.next(); err != nil { - if sm.dbl.logSuppressedErrors { - log.Printf("PCToLine error: %v", err) + if sm.dbl.Logf != nil { + sm.dbl.Logf("PCToLine error: %v", err) } break } @@ -276,8 +275,8 @@ func (lineInfo *DebugLineInfo) LineToPC(filename string, lineno int) uint64 { for { if err := sm.next(); err != nil { - if lineInfo.logSuppressedErrors { - log.Printf("LineToPC error: %v", err) + if lineInfo.Logf != nil { + lineInfo.Logf("LineToPC error: %v", err) } break } @@ -311,8 +310,8 @@ func (lineInfo *DebugLineInfo) PrologueEndPC(start, end uint64) (pc uint64, file } } if err := sm.next(); err != nil { - if lineInfo.logSuppressedErrors { - log.Printf("PrologueEnd error: %v", err) + if lineInfo.Logf != nil { + lineInfo.Logf("PrologueEnd error: %v", err) } return 0, "", 0, false } diff --git a/pkg/proc/gdbserial/gdbserver.go b/pkg/proc/gdbserial/gdbserver.go index 1c6dc526..9e0c39d6 100644 --- a/pkg/proc/gdbserial/gdbserver.go +++ b/pkg/proc/gdbserial/gdbserver.go @@ -68,6 +68,7 @@ import ( "errors" "fmt" "go/ast" + "io/ioutil" "net" "os" "os/exec" @@ -81,6 +82,7 @@ import ( "github.com/derekparker/delve/pkg/logflags" "github.com/derekparker/delve/pkg/proc" + "github.com/sirupsen/logrus" ) const ( @@ -166,11 +168,17 @@ type gdbRegister struct { // Detach. // Use Listen, Dial or Connect to complete connection. func New(process *os.Process) *Process { + logger := logrus.New().WithFields(logrus.Fields{"layer": "gdbconn"}) + logger.Level = logrus.DebugLevel + if !logflags.GdbWire() { + logger.Logger.Out = ioutil.Discard + } p := &Process{ conn: gdbConn{ maxTransmitAttempts: maxTransmitAttempts, inbuf: make([]byte, 0, initialInputBufferSize), direction: proc.Forward, + log: logger, }, threads: make(map[int]*Thread), bi: proc.NewBinaryInfo(runtime.GOOS, runtime.GOARCH), diff --git a/pkg/proc/gdbserial/gdbserver_conn.go b/pkg/proc/gdbserial/gdbserver_conn.go index 7be7c92d..163ec0db 100644 --- a/pkg/proc/gdbserial/gdbserver_conn.go +++ b/pkg/proc/gdbserial/gdbserver_conn.go @@ -18,6 +18,7 @@ import ( "github.com/derekparker/delve/pkg/logflags" "github.com/derekparker/delve/pkg/proc" + "github.com/sirupsen/logrus" ) type gdbConn struct { @@ -43,6 +44,8 @@ type gdbConn struct { maxTransmitAttempts int // maximum number of transmit or receive attempts when bad checksums are read threadSuffixSupported bool // thread suffix supported by stub isDebugserver bool // true if the stub is debugserver + + log *logrus.Entry } const ( @@ -634,7 +637,7 @@ func (conn *gdbConn) parseStopPacket(resp []byte, threadID string, tu *threadUpd sp.sig = uint8(sig) if logflags.GdbWire() && gdbWireFullStopPacket { - fmt.Fprintf(os.Stderr, "full stop packet: %s\n", string(resp)) + conn.log.Debug("full stop packet: %s\n", string(resp)) } buf := resp[3:] @@ -705,9 +708,7 @@ const ctrlC = 0x03 // the ASCII character for ^C // executes a ctrl-C on the line func (conn *gdbConn) sendCtrlC() error { - if logflags.GdbWire() { - fmt.Println("<- interrupt") - } + conn.log.Debug("<- interrupt") _, err := conn.conn.Write([]byte{ctrlC}) return err } @@ -994,9 +995,9 @@ func (conn *gdbConn) send(cmd []byte) error { for { if logflags.GdbWire() { if len(cmd) > gdbWireMaxLen { - fmt.Printf("<- %s...\n", string(cmd[:gdbWireMaxLen])) + conn.log.Debugf("<- %s...\n", string(cmd[:gdbWireMaxLen])) } else { - fmt.Printf("<- %s\n", string(cmd)) + conn.log.Debugf("<- %s\n", string(cmd)) } } _, err := conn.conn.Write(cmd) @@ -1045,9 +1046,9 @@ func (conn *gdbConn) recv(cmd []byte, context string, binary bool) (resp []byte, partial = true } if !partial { - fmt.Printf("-> %s%s\n", string(resp), string(conn.inbuf[:2])) + conn.log.Debugf("-> %s%s\n", string(resp), string(conn.inbuf[:2])) } else { - fmt.Printf("-> %s...\n", string(out)) + conn.log.Debugf("-> %s...\n", string(out)) } } @@ -1098,9 +1099,7 @@ func (conn *gdbConn) readack() bool { if err != nil { return false } - if logflags.GdbWire() { - fmt.Printf("-> %s\n", string(b)) - } + conn.log.Debugf("-> %s\n", string(b)) return b == '+' } @@ -1110,9 +1109,7 @@ func (conn *gdbConn) sendack(c byte) { panic(fmt.Errorf("sendack(%c)", c)) } conn.conn.Write([]byte{c}) - if logflags.GdbWire() { - fmt.Printf("<- %s\n", string(c)) - } + conn.log.Debugf("<- %s\n", string(c)) } // escapeXor is the value mandated by the specification to escape characters diff --git a/pkg/proc/types.go b/pkg/proc/types.go index d9b41f11..b002abc0 100644 --- a/pkg/proc/types.go +++ b/pkg/proc/types.go @@ -24,6 +24,7 @@ import ( "github.com/derekparker/delve/pkg/dwarf/reader" "github.com/derekparker/delve/pkg/goversion" "github.com/derekparker/delve/pkg/logflags" + "github.com/sirupsen/logrus" ) // The kind field in runtime._type is a reflect.Kind value plus @@ -220,8 +221,15 @@ func (bi *BinaryInfo) loadDebugInfoMaps(debugLineBytes []byte, wg *sync.WaitGrou } lineInfoOffset, _ := entry.Val(dwarf.AttrStmtList).(int64) if lineInfoOffset >= 0 && lineInfoOffset < int64(len(debugLineBytes)) { - cu.lineInfo = line.Parse(compdir, bytes.NewBuffer(debugLineBytes[lineInfoOffset:])) - cu.lineInfo.LogSuppressedErrors(logflags.DebugLineErrors()) + var logfn func(string, ...interface{}) + if logflags.DebugLineErrors() { + logger := logrus.New().WithFields(logrus.Fields{"layer": "dwarf-line"}) + logger.Level = logrus.DebugLevel + logfn = func(fmt string, args ...interface{}) { + logger.Printf(fmt, args) + } + } + cu.lineInfo = line.Parse(compdir, bytes.NewBuffer(debugLineBytes[lineInfoOffset:]), logfn) } cu.producer, _ = entry.Val(dwarf.AttrProducer).(string) if cu.isgo && cu.producer != "" { diff --git a/pkg/terminal/command_test.go b/pkg/terminal/command_test.go index 40b742d0..1ad07b7e 100644 --- a/pkg/terminal/command_test.go +++ b/pkg/terminal/command_test.go @@ -113,7 +113,7 @@ func withTestTerminalBuildFlags(name string, t testing.TB, buildFlags test.Build Listener: listener, ProcessArgs: []string{test.BuildFixture(name, buildFlags).Path}, Backend: testBackend, - }, false) + }) if err := server.Run(); err != nil { t.Fatal(err) } diff --git a/service/debugger/debugger.go b/service/debugger/debugger.go index bf6d4632..9f4cbed9 100644 --- a/service/debugger/debugger.go +++ b/service/debugger/debugger.go @@ -4,7 +4,7 @@ import ( "errors" "fmt" "go/parser" - "log" + "io/ioutil" "path/filepath" "regexp" "runtime" @@ -18,6 +18,7 @@ import ( "github.com/derekparker/delve/pkg/proc/gdbserial" "github.com/derekparker/delve/pkg/proc/native" "github.com/derekparker/delve/service/api" + "github.com/sirupsen/logrus" ) // Debugger service. @@ -35,6 +36,7 @@ type Debugger struct { // TODO(DO NOT MERGE WITHOUT) rename to targetMutex processMutex sync.Mutex target proc.Process + log *logrus.Entry } // Config provides the configuration to start a Debugger. @@ -63,17 +65,21 @@ type Config struct { // New creates a new Debugger. ProcessArgs specify the commandline arguments for the // new process. func New(config *Config, processArgs []string) (*Debugger, error) { + logger := logrus.New().WithFields(logrus.Fields{"layer": "debugger"}) + logger.Level = logrus.DebugLevel + if !logflags.Debugger() { + logger.Logger.Out = ioutil.Discard + } d := &Debugger{ config: config, processArgs: processArgs, + log: logger, } // Create the process by either attaching or launching. switch { case d.config.AttachPid > 0: - if logflags.Debugger() { - log.Printf("attaching to pid %d", d.config.AttachPid) - } + d.log.Infof("attaching to pid %d", d.config.AttachPid) path := "" if len(d.processArgs) > 0 { path = d.processArgs[0] @@ -89,14 +95,10 @@ func New(config *Config, processArgs []string) (*Debugger, error) { var err error switch d.config.Backend { case "rr": - if logflags.Debugger() { - log.Printf("opening trace %s", d.config.CoreFile) - } + d.log.Infof("opening trace %s", d.config.CoreFile) p, err = gdbserial.Replay(d.config.CoreFile, false) default: - if logflags.Debugger() { - log.Printf("opening core file %s (executable %s)", d.config.CoreFile, d.processArgs[0]) - } + d.log.Infof("opening core file %s (executable %s)", d.config.CoreFile, d.processArgs[0]) p, err = core.OpenCore(d.config.CoreFile, d.processArgs[0]) } if err != nil { @@ -105,9 +107,7 @@ func New(config *Config, processArgs []string) (*Debugger, error) { d.target = p default: - if logflags.Debugger() { - log.Printf("launching process with args: %v", d.processArgs) - } + d.log.Infof("launching process with args: %v", d.processArgs) p, err := d.Launch(d.processArgs, d.config.WorkingDir) if err != nil { if err != proc.NotExecutableErr && err != proc.UnsupportedLinuxArchErr && err != proc.UnsupportedWindowsArchErr && err != proc.UnsupportedDarwinArchErr { @@ -367,9 +367,7 @@ func (d *Debugger) CreateBreakpoint(requestedBp *api.Breakpoint) (*api.Breakpoin return nil, err } createdBp = api.ConvertBreakpoint(bp) - if logflags.Debugger() { - log.Printf("created breakpoint: %#v", createdBp) - } + d.log.Infof("created breakpoint: %#v", createdBp) return createdBp, nil } @@ -417,9 +415,7 @@ func (d *Debugger) ClearBreakpoint(requestedBp *api.Breakpoint) (*api.Breakpoint return nil, fmt.Errorf("Can't clear breakpoint @%x: %s", requestedBp.Addr, err) } clearedBp = api.ConvertBreakpoint(bp) - if logflags.Debugger() { - log.Printf("cleared breakpoint: %#v", clearedBp) - } + d.log.Infof("cleared breakpoint: %#v", clearedBp) return clearedBp, err } @@ -517,9 +513,7 @@ func (d *Debugger) Command(command *api.DebuggerCommand) (*api.DebuggerState, er if command.Name == api.Halt { // RequestManualStop does not invoke any ptrace syscalls, so it's safe to // access the process directly. - if logflags.Debugger() { - log.Print("halting") - } + d.log.Debug("halting") err = d.target.RequestManualStop() } @@ -530,14 +524,10 @@ func (d *Debugger) Command(command *api.DebuggerCommand) (*api.DebuggerState, er switch command.Name { case api.Continue: - if logflags.Debugger() { - log.Print("continuing") - } + d.log.Debug("continuing") err = proc.Continue(d.target) case api.Rewind: - if logflags.Debugger() { - log.Print("rewinding") - } + d.log.Debug("rewinding") if err := d.target.Direction(proc.Backward); err != nil { return nil, err } @@ -546,35 +536,23 @@ func (d *Debugger) Command(command *api.DebuggerCommand) (*api.DebuggerState, er }() err = proc.Continue(d.target) case api.Next: - if logflags.Debugger() { - log.Print("nexting") - } + d.log.Debug("nexting") err = proc.Next(d.target) case api.Step: - if logflags.Debugger() { - log.Print("stepping") - } + d.log.Debug("stepping") err = proc.Step(d.target) case api.StepInstruction: - if logflags.Debugger() { - log.Print("single stepping") - } + d.log.Debug("single stepping") err = d.target.StepInstruction() case api.StepOut: - if logflags.Debugger() { - log.Print("step out") - } + d.log.Debug("step out") err = proc.StepOut(d.target) case api.SwitchThread: - if logflags.Debugger() { - log.Printf("switching to thread %d", command.ThreadID) - } + d.log.Debugf("switching to thread %d", command.ThreadID) err = d.target.SwitchThread(command.ThreadID) withBreakpointInfo = false case api.SwitchGoroutine: - if logflags.Debugger() { - log.Printf("switching to goroutine %d", command.GoroutineID) - } + d.log.Debugf("switching to goroutine %d", command.GoroutineID) err = d.target.SwitchGoroutine(command.GoroutineID) withBreakpointInfo = false case api.Halt: diff --git a/service/rpccommon/server.go b/service/rpccommon/server.go index 5af6f64f..5c6486ab 100644 --- a/service/rpccommon/server.go +++ b/service/rpccommon/server.go @@ -6,7 +6,7 @@ import ( "errors" "fmt" "io" - "log" + "io/ioutil" "net" "net/rpc" "net/rpc/jsonrpc" @@ -16,12 +16,14 @@ import ( "unicode" "unicode/utf8" + "github.com/derekparker/delve/pkg/logflags" "github.com/derekparker/delve/pkg/version" "github.com/derekparker/delve/service" "github.com/derekparker/delve/service/api" "github.com/derekparker/delve/service/debugger" "github.com/derekparker/delve/service/rpc1" "github.com/derekparker/delve/service/rpc2" + "github.com/sirupsen/logrus" ) // ServerImpl implements a JSON-RPC server that can switch between two @@ -41,7 +43,7 @@ type ServerImpl struct { s2 *rpc2.RPCServer // maps of served methods, one for each supported API. methodMaps []map[string]*methodType - log bool + log *logrus.Entry } type RPCCallback struct { @@ -65,17 +67,24 @@ type methodType struct { } // NewServer creates a new RPCServer. -func NewServer(config *service.Config, logEnabled bool) *ServerImpl { +func NewServer(config *service.Config) *ServerImpl { + logger := logrus.New().WithFields(logrus.Fields{"layer": "rpc"}) + logger.Level = logrus.DebugLevel + if !logflags.RPC() { + logger.Logger.Out = ioutil.Discard + } if config.APIVersion < 2 { - if logEnabled { - log.Printf("Using API v1") - } + logger.Info("Using API v1") + } + if config.Foreground { + // Print listener address + logger.Infof("API server listening at: %s", config.Listener.Addr()) } return &ServerImpl{ config: config, listener: config.Listener, stopChan: make(chan struct{}), - log: logEnabled, + log: logger, } } @@ -183,14 +192,12 @@ func isExportedOrBuiltinType(t reflect.Type) bool { // two signatures: // func (rcvr ReceiverType) Method(in InputType, out *ReplyType) error // func (rcvr ReceiverType) Method(in InputType, cb service.RPCCallback) -func suitableMethods(rcvr interface{}, methods map[string]*methodType, logEnabled bool) { +func suitableMethods(rcvr interface{}, methods map[string]*methodType, log *logrus.Entry) { typ := reflect.TypeOf(rcvr) rcvrv := reflect.ValueOf(rcvr) sname := reflect.Indirect(rcvrv).Type().Name() if sname == "" { - if logEnabled { - log.Printf("rpc.Register: no service name for type %s", typ) - } + log.Debugf("rpc.Register: no service name for type %s", typ) return } for m := 0; m < typ.NumMethod(); m++ { @@ -203,17 +210,13 @@ func suitableMethods(rcvr interface{}, methods map[string]*methodType, logEnable } // Method needs three ins: (receive, *args, *reply) or (receiver, *args, *RPCCallback) if mtype.NumIn() != 3 { - if logEnabled { - log.Println("method", mname, "has wrong number of ins:", mtype.NumIn()) - } + log.Warn("method", mname, "has wrong number of ins:", mtype.NumIn()) continue } // First arg need not be a pointer. argType := mtype.In(1) if !isExportedOrBuiltinType(argType) { - if logEnabled { - log.Println(mname, "argument type not exported:", argType) - } + log.Warn(mname, "argument type not exported:", argType) continue } @@ -223,39 +226,29 @@ func suitableMethods(rcvr interface{}, methods map[string]*methodType, logEnable if synchronous { // Second arg must be a pointer. if replyType.Kind() != reflect.Ptr { - if logEnabled { - log.Println("method", mname, "reply type not a pointer:", replyType) - } + log.Warn("method", mname, "reply type not a pointer:", replyType) continue } // Reply type must be exported. if !isExportedOrBuiltinType(replyType) { - if logEnabled { - log.Println("method", mname, "reply type not exported:", replyType) - } + log.Warn("method", mname, "reply type not exported:", replyType) continue } // Method needs one out. if mtype.NumOut() != 1 { - if logEnabled { - log.Println("method", mname, "has wrong number of outs:", mtype.NumOut()) - } + log.Warn("method", mname, "has wrong number of outs:", mtype.NumOut()) continue } // The return type of the method must be error. if returnType := mtype.Out(0); returnType != typeOfError { - if logEnabled { - log.Println("method", mname, "returns", returnType.String(), "not error") - } + log.Warn("method", mname, "returns", returnType.String(), "not error") continue } } else { // Method needs zero outs. if mtype.NumOut() != 0 { - if logEnabled { - log.Println("method", mname, "has wrong number of outs:", mtype.NumOut()) - } + log.Warn("method", mname, "has wrong number of outs:", mtype.NumOut()) continue } } @@ -273,18 +266,14 @@ func (s *ServerImpl) serveJSONCodec(conn io.ReadWriteCloser) { err := codec.ReadRequestHeader(&req) if err != nil { if err != io.EOF { - if s.log { - log.Println("rpc:", err) - } + s.log.Error("rpc:", err) } break } mtype, ok := s.methodMaps[s.config.APIVersion-1][req.ServiceMethod] if !ok { - if s.log { - log.Printf("rpc: can't find method %s", req.ServiceMethod) - } + s.log.Errorf("rpc: can't find method %s", req.ServiceMethod) continue } @@ -307,9 +296,9 @@ func (s *ServerImpl) serveJSONCodec(conn io.ReadWriteCloser) { } if mtype.Synchronous { - if s.log { + if logflags.RPC() { argvbytes, _ := json.Marshal(argv.Interface()) - log.Printf("-> %s(%T%s)\n", req.ServiceMethod, argv.Interface(), argvbytes) + s.log.Debugf("-> %s(%T%s)\n", req.ServiceMethod, argv.Interface(), argvbytes) } replyv = reflect.New(mtype.ReplyType.Elem()) function := mtype.method.Func @@ -330,15 +319,15 @@ func (s *ServerImpl) serveJSONCodec(conn io.ReadWriteCloser) { errmsg = errInter.(error).Error() } resp = rpc.Response{} - if s.log { + if logflags.RPC() { replyvbytes, _ := json.Marshal(replyv.Interface()) - log.Printf("<- %T%s error: %q\n", replyv.Interface(), replyvbytes, errmsg) + s.log.Debugf("<- %T%s error: %q\n", replyv.Interface(), replyvbytes, errmsg) } s.sendResponse(sending, &req, &resp, replyv.Interface(), codec, errmsg) } else { - if s.log { + if logflags.RPC() { argvbytes, _ := json.Marshal(argv.Interface()) - log.Printf("(async %d) -> %s(%T%s)\n", req.Seq, req.ServiceMethod, argv.Interface(), argvbytes) + s.log.Debugf("(async %d) -> %s(%T%s)\n", req.Seq, req.ServiceMethod, argv.Interface(), argvbytes) } function := mtype.method.Func ctl := &RPCCallback{s, sending, codec, req} @@ -374,9 +363,7 @@ func (s *ServerImpl) sendResponse(sending *sync.Mutex, req *rpc.Request, resp *r defer sending.Unlock() err := codec.WriteResponse(resp, reply) if err != nil { - if s.log { - log.Println("rpc: writing response:", err) - } + s.log.Error("writing response:", err) } } @@ -386,9 +373,9 @@ func (cb *RPCCallback) Return(out interface{}, err error) { errmsg = err.Error() } var resp rpc.Response - if cb.s.log { + if logflags.RPC() { outbytes, _ := json.Marshal(out) - log.Printf("(async %d) <- %T%s error: %q", cb.req.Seq, out, outbytes, errmsg) + cb.s.log.Debugf("(async %d) <- %T%s error: %q", cb.req.Seq, out, outbytes, errmsg) } cb.s.sendResponse(cb.sending, &cb.req, &resp, out, cb.codec, errmsg) } diff --git a/service/test/integration1_test.go b/service/test/integration1_test.go index 21ee5e02..0559a5f5 100644 --- a/service/test/integration1_test.go +++ b/service/test/integration1_test.go @@ -33,7 +33,7 @@ func withTestClient1(name string, t *testing.T, fn func(c *rpc1.RPCClient)) { Listener: listener, ProcessArgs: []string{protest.BuildFixture(name, 0).Path}, Backend: testBackend, - }, false) + }) if err := server.Run(); err != nil { t.Fatal(err) } @@ -61,7 +61,7 @@ func Test1RunWithInvalidPath(t *testing.T) { Listener: listener, ProcessArgs: []string{"invalid_path"}, Backend: testBackend, - }, false) + }) if err := server.Run(); err == nil { t.Fatal("Expected Run to return error for invalid program path") } @@ -150,7 +150,7 @@ func Test1Restart_attachPid(t *testing.T) { Listener: nil, AttachPid: 999, Backend: testBackend, - }, false) + }) if err := server.Restart(); err == nil { t.Fatal("expected error on restart after attaching to pid but got none") } diff --git a/service/test/integration2_test.go b/service/test/integration2_test.go index dc738a10..754292e4 100644 --- a/service/test/integration2_test.go +++ b/service/test/integration2_test.go @@ -51,7 +51,7 @@ func withTestClient2(name string, t *testing.T, fn func(c service.Client)) { Listener: listener, ProcessArgs: []string{protest.BuildFixture(name, 0).Path}, Backend: testBackend, - }, false) + }) if err := server.Run(); err != nil { t.Fatal(err) } @@ -84,7 +84,7 @@ func TestRunWithInvalidPath(t *testing.T) { ProcessArgs: []string{"invalid_path"}, APIVersion: 2, Backend: testBackend, - }, false) + }) if err := server.Run(); err == nil { t.Fatal("Expected Run to return error for invalid program path") } @@ -175,7 +175,7 @@ func TestRestart_attachPid(t *testing.T) { AttachPid: 999, APIVersion: 2, Backend: testBackend, - }, false) + }) if err := server.Restart(); err == nil { t.Fatal("expected error on restart after attaching to pid but got none") }