Repository: incubator-htrace Updated Branches: refs/heads/master 8a4c9e577 -> 85e3d3e93
HTRACE-162. htraced hrpc: some logging improvements (cmccabe) Project: http://git-wip-us.apache.org/repos/asf/incubator-htrace/repo Commit: http://git-wip-us.apache.org/repos/asf/incubator-htrace/commit/85e3d3e9 Tree: http://git-wip-us.apache.org/repos/asf/incubator-htrace/tree/85e3d3e9 Diff: http://git-wip-us.apache.org/repos/asf/incubator-htrace/diff/85e3d3e9 Branch: refs/heads/master Commit: 85e3d3e9329b02746e981ad77b77acee5fd33653 Parents: 8a4c9e5 Author: Colin P. Mccabe <[email protected]> Authored: Thu Apr 30 16:12:44 2015 -0700 Committer: Colin P. Mccabe <[email protected]> Committed: Thu May 7 16:03:11 2015 -0700 ---------------------------------------------------------------------- htrace-c/src/test/mini_htraced.c | 13 ++++++-- htrace-c/src/test/mini_htraced.h | 6 ++++ .../src/go/src/org/apache/htrace/common/log.go | 22 ++++++------- .../src/org/apache/htrace/htraced/datastore.go | 16 ++++----- .../go/src/org/apache/htrace/htraced/hrpc.go | 34 ++++++++++++-------- 5 files changed, 57 insertions(+), 34 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/incubator-htrace/blob/85e3d3e9/htrace-c/src/test/mini_htraced.c ---------------------------------------------------------------------- diff --git a/htrace-c/src/test/mini_htraced.c b/htrace-c/src/test/mini_htraced.c index d97a01b..ab9eb08 100644 --- a/htrace-c/src/test/mini_htraced.c +++ b/htrace-c/src/test/mini_htraced.c @@ -472,7 +472,7 @@ void mini_htraced_dump_spans(struct mini_htraced *ht, { pid_t pid; int ret; - char *addr = NULL; + char *addr = NULL, *log_path = NULL; err[0] = '\0'; if (asprintf(&addr, "--addr=%s", ht->htraced_http_addr) < 0) { @@ -480,9 +480,18 @@ void mini_htraced_dump_spans(struct mini_htraced *ht, snprintf(err, err_len, "OOM while allocating the addr string"); return; } + if (asprintf(&log_path, "--Dlog.path=%s/htrace.%05"PRId64".log", + ht->root_dir, ht->num_htrace_commands_run) < 0) { + log_path = NULL; + snprintf(err, err_len, "OOM while allocating the addr string"); + free(addr); + return; + } + ht->num_htrace_commands_run++; pid = mini_htraced_launch(ht, HTRACE_ABSPATH, err, err_len, 0, - addr, "dumpAll", path, NULL); + addr, log_path, "dumpAll", path, NULL); free(addr); + free(log_path); if (err[0]) { return; } http://git-wip-us.apache.org/repos/asf/incubator-htrace/blob/85e3d3e9/htrace-c/src/test/mini_htraced.h ---------------------------------------------------------------------- diff --git a/htrace-c/src/test/mini_htraced.h b/htrace-c/src/test/mini_htraced.h index df999cc..8672a36 100644 --- a/htrace-c/src/test/mini_htraced.h +++ b/htrace-c/src/test/mini_htraced.h @@ -29,6 +29,7 @@ * This is an internal header, not intended for external use. */ +#include <stdint.h> /* for uint64_t, etc. */ #include <unistd.h> /* for pid_t and size_t */ struct htrace_conf; @@ -111,6 +112,11 @@ struct mini_htraced { * The HRPC address of the htraced, in hostname:port format. */ char *htraced_hrpc_addr; + + /** + * The number of htrace commands that have been run. + */ + uint64_t num_htrace_commands_run; }; /** http://git-wip-us.apache.org/repos/asf/incubator-htrace/blob/85e3d3e9/htrace-htraced/src/go/src/org/apache/htrace/common/log.go ---------------------------------------------------------------------- diff --git a/htrace-htraced/src/go/src/org/apache/htrace/common/log.go b/htrace-htraced/src/go/src/org/apache/htrace/common/log.go index edec869..305ecf3 100644 --- a/htrace-htraced/src/go/src/org/apache/htrace/common/log.go +++ b/htrace-htraced/src/go/src/org/apache/htrace/common/log.go @@ -210,52 +210,52 @@ func parseConf(faculty string, cnf *conf.Config) (string, Level) { } func (lg *Logger) Trace(str string) { - lg.write(TRACE, str) + lg.Write(TRACE, str) } func (lg *Logger) Tracef(format string, v ...interface{}) { - lg.write(TRACE, fmt.Sprintf(format, v...)) + lg.Write(TRACE, fmt.Sprintf(format, v...)) } func (lg *Logger) Debug(str string) { - lg.write(DEBUG, str) + lg.Write(DEBUG, str) } func (lg *Logger) Debugf(format string, v ...interface{}) { - lg.write(DEBUG, fmt.Sprintf(format, v...)) + lg.Write(DEBUG, fmt.Sprintf(format, v...)) } func (lg *Logger) Info(str string) { - lg.write(INFO, str) + lg.Write(INFO, str) } func (lg *Logger) Infof(format string, v ...interface{}) { - lg.write(INFO, fmt.Sprintf(format, v...)) + lg.Write(INFO, fmt.Sprintf(format, v...)) } func (lg *Logger) Warn(str string) error { - lg.write(WARN, str) + lg.Write(WARN, str) return errors.New(str) } func (lg *Logger) Warnf(format string, v ...interface{}) error { str := fmt.Sprintf(format, v...) - lg.write(WARN, str) + lg.Write(WARN, str) return errors.New(str) } func (lg *Logger) Error(str string) error { - lg.write(ERROR, str) + lg.Write(ERROR, str) return errors.New(str) } func (lg *Logger) Errorf(format string, v ...interface{}) error { str := fmt.Sprintf(format, v...) - lg.write(ERROR, str) + lg.Write(ERROR, str) return errors.New(str) } -func (lg *Logger) write(level Level, str string) { +func (lg *Logger) Write(level Level, str string) { if level >= lg.Level { lg.sink.write(time.Now().Format(time.RFC3339) + " " + level.LogString() + ": " + str) http://git-wip-us.apache.org/repos/asf/incubator-htrace/blob/85e3d3e9/htrace-htraced/src/go/src/org/apache/htrace/htraced/datastore.go ---------------------------------------------------------------------- diff --git a/htrace-htraced/src/go/src/org/apache/htrace/htraced/datastore.go b/htrace-htraced/src/go/src/org/apache/htrace/htraced/datastore.go index 97af3fb..b9dc484 100644 --- a/htrace-htraced/src/go/src/org/apache/htrace/htraced/datastore.go +++ b/htrace-htraced/src/go/src/org/apache/htrace/htraced/datastore.go @@ -480,15 +480,15 @@ func (shd *shard) FindSpan(sid common.SpanId) *common.Span { if strings.Index(err.Error(), "NotFound:") != -1 { return nil } - lg.Warnf("Shard(%s): FindSpan(%016x) error: %s\n", - shd.path, sid, err.Error()) + lg.Warnf("Shard(%s): FindSpan(%s) error: %s\n", + shd.path, sid.String(), err.Error()) return nil } var span *common.Span span, err = shd.decodeSpan(sid, buf) if err != nil { - lg.Errorf("Shard(%s): FindSpan(%016x) decode error: %s\n", - shd.path, sid, err.Error()) + lg.Errorf("Shard(%s): FindSpan(%s) decode error: %s\n", + shd.path, sid.String(), err.Error()) return nil } return span @@ -525,8 +525,8 @@ func (store *dataStore) FindChildren(sid common.SpanId, lim int32) []common.Span shd := store.shards[idx] childIds, lim, err = shd.FindChildren(sid, childIds, lim) if err != nil { - store.lg.Errorf("Shard(%s): FindChildren(%016x) error: %s\n", - shd.path, sid, err.Error()) + store.lg.Errorf("Shard(%s): FindChildren(%s) error: %s\n", + shd.path, sid.String(), err.Error()) } idx++ if idx >= numShards { @@ -887,8 +887,8 @@ func (src *source) populateNextFromShard(shardIdx int) { src.nexts[shardIdx] = span // Found valid entry return } else { - lg.Debugf("Span %016x from shard %d does not satisfy the predicate.\n", - sid, shardIdx) + lg.Debugf("Span %s from shard %d does not satisfy the predicate.\n", + sid.String(), shardIdx) if src.numRead[shardIdx] <= 1 && mayRequireOneSkip(src.pred.Op) { continue } http://git-wip-us.apache.org/repos/asf/incubator-htrace/blob/85e3d3e9/htrace-htraced/src/go/src/org/apache/htrace/htraced/hrpc.go ---------------------------------------------------------------------- diff --git a/htrace-htraced/src/go/src/org/apache/htrace/htraced/hrpc.go b/htrace-htraced/src/go/src/org/apache/htrace/htraced/hrpc.go index eede69e..b129268 100644 --- a/htrace-htraced/src/go/src/org/apache/htrace/htraced/hrpc.go +++ b/htrace-htraced/src/go/src/org/apache/htrace/htraced/hrpc.go @@ -60,8 +60,12 @@ func asJson(val interface{}) string { return string(js) } -func createErrAndLog(lg *common.Logger, val string) error { - lg.Warnf("%s\n", val) +func createErrAndWarn(lg *common.Logger, val string) error { + return createErrAndLog(lg, val, common.WARN) +} + +func createErrAndLog(lg *common.Logger, val string, level common.Level) error { + lg.Write(level, val + "\n") return errors.New(val) } @@ -72,25 +76,29 @@ func (cdc *HrpcServerCodec) ReadRequestHeader(req *rpc.Request) error { } err := binary.Read(cdc.conn, binary.LittleEndian, &hdr) if err != nil { + level := common.WARN + if err == io.EOF { + level = common.DEBUG + } return createErrAndLog(cdc.lg, fmt.Sprintf("Error reading header bytes: %s", - err.Error())) + err.Error()), level) } if cdc.lg.TraceEnabled() { cdc.lg.Tracef("Read HRPC request header %s from %s\n", asJson(&hdr), cdc.conn.RemoteAddr()) } if hdr.Magic != common.HRPC_MAGIC { - return createErrAndLog(cdc.lg, fmt.Sprintf("Invalid request header: expected "+ + return createErrAndWarn(cdc.lg, fmt.Sprintf("Invalid request header: expected "+ "magic number of 0x%04x, but got 0x%04x", common.HRPC_MAGIC, hdr.Magic)) } if hdr.Length > common.MAX_HRPC_BODY_LENGTH { - return createErrAndLog(cdc.lg, fmt.Sprintf("Length prefix was too long. "+ + return createErrAndWarn(cdc.lg, fmt.Sprintf("Length prefix was too long. "+ "Maximum length is %d, but we got %d.", common.MAX_HRPC_BODY_LENGTH, hdr.Length)) } req.ServiceMethod = common.HrpcMethodIdToMethodName(hdr.MethodId) if req.ServiceMethod == "" { - return createErrAndLog(cdc.lg, fmt.Sprintf("Unknown MethodID code 0x%04x", + return createErrAndWarn(cdc.lg, fmt.Sprintf("Unknown MethodID code 0x%04x", hdr.MethodId)) } req.Seq = hdr.Seq @@ -106,7 +114,7 @@ func (cdc *HrpcServerCodec) ReadRequestBody(body interface{}) error { dec := json.NewDecoder(io.LimitReader(cdc.conn, int64(cdc.length))) err := dec.Decode(body) if err != nil { - return createErrAndLog(cdc.lg, fmt.Sprintf("Failed to read request "+ + return createErrAndWarn(cdc.lg, fmt.Sprintf("Failed to read request "+ "body from %s: %s", cdc.conn.RemoteAddr(), err.Error())) } if cdc.lg.TraceEnabled() { @@ -124,7 +132,7 @@ func (cdc *HrpcServerCodec) WriteResponse(resp *rpc.Response, msg interface{}) e if msg != nil { buf, err = json.Marshal(msg) if err != nil { - return createErrAndLog(cdc.lg, fmt.Sprintf("Failed to marshal "+ + return createErrAndWarn(cdc.lg, fmt.Sprintf("Failed to marshal "+ "response message: %s", err.Error())) } } @@ -136,13 +144,13 @@ func (cdc *HrpcServerCodec) WriteResponse(resp *rpc.Response, msg interface{}) e writer := bufio.NewWriterSize(cdc.conn, 256) err = binary.Write(writer, binary.LittleEndian, &hdr) if err != nil { - return createErrAndLog(cdc.lg, fmt.Sprintf("Failed to write response "+ + return createErrAndWarn(cdc.lg, fmt.Sprintf("Failed to write response "+ "header: %s", err.Error())) } if hdr.ErrLength > 0 { _, err = io.WriteString(writer, resp.Error) if err != nil { - return createErrAndLog(cdc.lg, fmt.Sprintf("Failed to write error "+ + return createErrAndWarn(cdc.lg, fmt.Sprintf("Failed to write error "+ "string: %s", err.Error())) } } @@ -150,17 +158,17 @@ func (cdc *HrpcServerCodec) WriteResponse(resp *rpc.Response, msg interface{}) e var length int length, err = writer.Write(buf) if err != nil { - return createErrAndLog(cdc.lg, fmt.Sprintf("Failed to write response "+ + return createErrAndWarn(cdc.lg, fmt.Sprintf("Failed to write response "+ "message: %s", err.Error())) } if uint32(length) != hdr.Length { - return createErrAndLog(cdc.lg, fmt.Sprintf("Failed to write all of "+ + return createErrAndWarn(cdc.lg, fmt.Sprintf("Failed to write all of "+ "response message: %s", err.Error())) } } err = writer.Flush() if err != nil { - return createErrAndLog(cdc.lg, fmt.Sprintf("Failed to write the response "+ + return createErrAndWarn(cdc.lg, fmt.Sprintf("Failed to write the response "+ "bytes: %s", err.Error())) } return nil
