Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

initial logging improve #1616

Draft
wants to merge 3 commits into
base: master
Choose a base branch
from
+171 −171
Draft

initial logging improve #1616

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
311abba
initial logging improve
rekby Jan 28, 2025
9f3c43a
done coordinatino, discovery, driver logs
rekby Jan 29, 2025
483a002
rewrite logs for query service
rekby Jan 30, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion internal/topic/topicwriterinternal/writer_single_stream.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -126,7 +126,7 @@ func (w *SingleStreamWriter) start() {

func (w *SingleStreamWriter) initStream() (err error) {
traceOnDone := trace.TopicOnWriterInitStream(w.cfg.Tracer, w.cfg.reconnectorInstanceID, w.cfg.topic, w.cfg.producerID)
defer traceOnDone(w.SessionID, err)
defer func() { traceOnDone(w.SessionID, err) }()

req := w.createInitRequest()
if err = w.cfg.stream.Send(&req); err != nil {
Expand Down
72 changes: 36 additions & 36 deletions log/coordination.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -25,11 +25,11 @@ func internalCoordination(
return nil
}
ctx := with(*info.Context, TRACE, "ydb", "coordination", "new")
l.Log(ctx, "start")
l.Log(ctx, "starting coordination client...")
start := time.Now()

return func(info trace.CoordinationNewDoneInfo) {
l.Log(WithLevel(ctx, INFO), "done",
l.Log(WithLevel(ctx, INFO), "coordination client started",
kv.Latency(start),
kv.Version(),
)
Expand All @@ -40,18 +40,18 @@ func internalCoordination(
return nil
}
ctx := with(*info.Context, TRACE, "ydb", "coordination", "node", "create")
l.Log(ctx, "start",
l.Log(ctx, "starting coordination node...",
kv.String("path", info.Path),
)
start := time.Now()

return func(info trace.CoordinationCreateNodeDoneInfo) {
if info.Error == nil {
l.Log(WithLevel(ctx, INFO), "done",
l.Log(WithLevel(ctx, INFO), "coordination node started",
kv.Latency(start),
)
} else {
l.Log(WithLevel(ctx, ERROR), "fail",
l.Log(WithLevel(ctx, ERROR), "coordination node start failed",
kv.Latency(start),
kv.Version(),
)
Expand All @@ -63,18 +63,18 @@ func internalCoordination(
return nil
}
ctx := with(*info.Context, TRACE, "ydb", "coordination", "node", "alter")
l.Log(ctx, "start",
l.Log(ctx, "starting alter coordination node...",
kv.String("path", info.Path),
)
start := time.Now()

return func(info trace.CoordinationAlterNodeDoneInfo) {
if info.Error == nil {
l.Log(WithLevel(ctx, INFO), "done",
l.Log(WithLevel(ctx, INFO), "alter coordination node done",
kv.Latency(start),
)
} else {
l.Log(WithLevel(ctx, ERROR), "fail",
l.Log(WithLevel(ctx, ERROR), "alter coordination node failed",
kv.Latency(start),
kv.Version(),
)
Expand All @@ -86,18 +86,18 @@ func internalCoordination(
return nil
}
ctx := with(*info.Context, TRACE, "ydb", "coordination", "node", "drop")
l.Log(ctx, "start",
l.Log(ctx, "starting drop coordination node...",
kv.String("path", info.Path),
)
start := time.Now()

return func(info trace.CoordinationDropNodeDoneInfo) {
if info.Error == nil {
l.Log(WithLevel(ctx, INFO), "done",
l.Log(WithLevel(ctx, INFO), "coordination node dropped",
kv.Latency(start),
)
} else {
l.Log(WithLevel(ctx, ERROR), "fail",
l.Log(WithLevel(ctx, ERROR), "coordination node drop failed",
kv.Latency(start),
kv.Version(),
)
Expand All @@ -109,18 +109,18 @@ func internalCoordination(
return nil
}
ctx := with(*info.Context, TRACE, "ydb", "coordination", "node", "describe")
l.Log(ctx, "start",
l.Log(ctx, "starting describe coordination node...",
kv.String("path", info.Path),
)
start := time.Now()

return func(info trace.CoordinationDescribeNodeDoneInfo) {
if info.Error == nil {
l.Log(WithLevel(ctx, INFO), "done",
l.Log(WithLevel(ctx, INFO), "describe node started",
kv.Latency(start),
)
} else {
l.Log(WithLevel(ctx, ERROR), "fail",
l.Log(WithLevel(ctx, ERROR), "describe node start failed",
kv.Latency(start),
kv.Version(),
)
Expand All @@ -132,16 +132,16 @@ func internalCoordination(
return nil
}
ctx := with(*info.Context, TRACE, "ydb", "coordination", "node", "describe")
l.Log(ctx, "start")
l.Log(ctx, "starting create coordination session...")
start := time.Now()

return func(info trace.CoordinationSessionDoneInfo) {
if info.Error == nil {
l.Log(WithLevel(ctx, INFO), "done",
l.Log(WithLevel(ctx, INFO), "coordination session created",
kv.Latency(start),
)
} else {
l.Log(WithLevel(ctx, ERROR), "fail",
l.Log(WithLevel(ctx, ERROR), "create coordination session failed",
kv.Latency(start),
kv.Version(),
)
Expand All @@ -153,16 +153,16 @@ func internalCoordination(
return nil
}
ctx := with(*info.Context, TRACE, "ydb", "coordination", "close")
l.Log(ctx, "start")
l.Log(ctx, "start closing coordination client...")
start := time.Now()

return func(info trace.CoordinationCloseDoneInfo) {
if info.Error == nil {
l.Log(WithLevel(ctx, INFO), "done",
l.Log(WithLevel(ctx, INFO), "coordination client closed",
kv.Latency(start),
)
} else {
l.Log(WithLevel(ctx, ERROR), "fail",
l.Log(WithLevel(ctx, ERROR), "close coordination client failed",
kv.Latency(start),
kv.Version(),
)
Expand All @@ -178,11 +178,11 @@ func internalCoordination(
return nil
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "stream", "new")
l.Log(ctx, "stream")
l.Log(ctx, "starting new coordination session stam...")
start := time.Now()

return func(info trace.CoordinationSessionNewStreamDoneInfo) {
l.Log(ctx, "done",
l.Log(ctx, "new coordination session stream started",
kv.Latency(start),
kv.Error(info.Error),
kv.Version(),
Expand All @@ -194,7 +194,7 @@ func internalCoordination(
return
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "started")
l.Log(ctx, "",
l.Log(ctx, "coordination session started",
kv.String("sessionID", strconv.FormatUint(info.SessionID, 10)),
kv.String("expectedSessionID", strconv.FormatUint(info.SessionID, 10)),
)
Expand All @@ -204,7 +204,7 @@ func internalCoordination(
return
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "start", "timeout")
l.Log(ctx, "",
l.Log(ctx, "coordination session start timeout",
kv.Stringer("timeout", info.Timeout),
)
},
Expand All @@ -213,7 +213,7 @@ func internalCoordination(
return
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "keepAlive", "timeout")
l.Log(ctx, "",
l.Log(ctx, "coordination session keep alive timeout",
kv.Stringer("timeout", info.Timeout),
kv.Stringer("lastGoodResponseTime", info.LastGoodResponseTime),
)
Expand All @@ -223,7 +223,7 @@ func internalCoordination(
return
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "stopped")
l.Log(ctx, "",
l.Log(ctx, "coordination session stopped",
kv.String("sessionID", strconv.FormatUint(info.SessionID, 10)),
kv.String("expectedSessionID", strconv.FormatUint(info.SessionID, 10)),
)
Expand All @@ -233,7 +233,7 @@ func internalCoordination(
return
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "stop", "timeout")
l.Log(ctx, "",
l.Log(ctx, "coordination session stop timeout",
kv.Stringer("timeout", info.Timeout),
)
},
Expand All @@ -242,7 +242,7 @@ func internalCoordination(
return
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "client", "timeout")
l.Log(ctx, "",
l.Log(ctx, "coordination session client timeout",
kv.Stringer("timeout", info.Timeout),
kv.Stringer("lastGoodResponseTime", info.LastGoodResponseTime),
)
Expand All @@ -252,7 +252,7 @@ func internalCoordination(
return
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "server", "expire")
l.Log(ctx, "",
l.Log(ctx, "coordination session server expire",
kv.Stringer("failure", info.Failure),
)
},
Expand All @@ -261,7 +261,7 @@ func internalCoordination(
return
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "server", "error")
l.Log(ctx, "",
l.Log(ctx, "coordination session server error",
kv.Stringer("failure", info.Failure),
)
},
Expand All @@ -274,11 +274,11 @@ func internalCoordination(
return nil
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "receive")
l.Log(ctx, "receive")
l.Log(ctx, "starting coordination session receive")
start := time.Now()

return func(info trace.CoordinationSessionReceiveDoneInfo) {
l.Log(ctx, "done",
l.Log(ctx, "coordination session received",
kv.Latency(start),
kv.Error(info.Error),
kv.Stringer("response", info.Response),
Expand All @@ -291,7 +291,7 @@ func internalCoordination(
return
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "receive", "unexpected")
l.Log(ctx, "",
l.Log(ctx, "coordination session received unexpected",
kv.Stringer("response", info.Response),
)
},
Expand All @@ -300,7 +300,7 @@ func internalCoordination(
return
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "stop")
l.Log(ctx, "",
l.Log(ctx, "coordination session stopped",
kv.String("sessionID", strconv.FormatUint(info.SessionID, 10)),
)
},
Expand All @@ -313,11 +313,11 @@ func internalCoordination(
return nil
}
ctx := with(context.Background(), TRACE, "ydb", "coordination", "session", "start")
l.Log(ctx, "start")
l.Log(ctx, "starting coordination session...")
start := time.Now()

return func(info trace.CoordinationSessionStartDoneInfo) {
l.Log(ctx, "done",
l.Log(ctx, "coordination session start done",
kv.Latency(start),
kv.Error(info.Error),
kv.Version(),
Expand Down
12 changes: 6 additions & 6 deletions log/discovery.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,20 +18,20 @@ func internalDiscovery(l Logger, d trace.Detailer) (t trace.Discovery) {
return nil
}
ctx := with(*info.Context, DEBUG, "ydb", "discovery", "list", "endpoints")
l.Log(ctx, "start",
l.Log(ctx, "starting discovery...",
kv.String("address", info.Address),
kv.String("database", info.Database),
)
start := time.Now()

return func(info trace.DiscoveryDiscoverDoneInfo) {
if info.Error == nil {
l.Log(WithLevel(ctx, INFO), "done",
l.Log(WithLevel(ctx, INFO), "discovery done",
kv.Latency(start),
kv.Stringer("endpoints", kv.Endpoints(info.Endpoints)),
)
} else {
l.Log(WithLevel(ctx, ERROR), "failed",
l.Log(WithLevel(ctx, ERROR), "discovery failed",
kv.Error(info.Error),
kv.Latency(start),
kv.Version(),
Expand All @@ -44,18 +44,18 @@ func internalDiscovery(l Logger, d trace.Detailer) (t trace.Discovery) {
return nil
}
ctx := with(*info.Context, TRACE, "ydb", "discovery", "whoAmI")
l.Log(ctx, "start")
l.Log(ctx, "starting discovery whoami")
start := time.Now()

return func(info trace.DiscoveryWhoAmIDoneInfo) {
if info.Error == nil {
l.Log(ctx, "done",
l.Log(ctx, "discovery whoami done",
kv.Latency(start),
kv.String("user", info.User),
kv.Strings("groups", info.Groups),
)
} else {
l.Log(WithLevel(ctx, WARN), "failed",
l.Log(WithLevel(ctx, WARN), "discovery whoami failed",
kv.Error(info.Error),
kv.Latency(start),
kv.Version(),
Expand Down
Loading
Loading