Skip to content

Commit c3b9d1c

Browse files
rekbyrekby
committed
improve logs
1 parent 483a002 commit c3b9d1c

File tree

5 files changed

+168
-168
lines changed

5 files changed

+168
-168
lines changed

‎log/retry.go‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@ func internalRetry(l Logger, d trace.Detailer) (t trace.Retry) {
1919
if d.Details()&trace.RetryEvents == 0 {
2020
return nil
2121
}
22-
ctx := with(*info.Context, TRACE, "ydb", "retry")
22+
ctx := with(*info.Context, TRACE, "ydb retrier starting work...", "retry")
2323
label := info.Label
2424
idempotent := info.Idempotent
2525
l.Log(ctx, "start",
@@ -30,7 +30,7 @@ func internalRetry(l Logger, d trace.Detailer) (t trace.Retry) {
3030

3131
return func(info trace.RetryLoopDoneInfo) {
3232
if info.Error == nil {
33-
l.Log(ctx, "done",
33+
l.Log(ctx, "ydb retries completed succesfully",
3434
kv.String("label", label),
3535
kv.Latency(start),
3636
kv.Int("attempts", info.Attempts),
@@ -41,7 +41,7 @@ func internalRetry(l Logger, d trace.Detailer) (t trace.Retry) {
4141
lvl = DEBUG
4242
}
4343
m := retry.Check(info.Error)
44-
l.Log(WithLevel(ctx, lvl), "failed",
44+
l.Log(WithLevel(ctx, lvl), "ydb retries failed",
4545
kv.Error(info.Error),
4646
kv.String("label", label),
4747
kv.Latency(start),

‎log/scripting.go‎

Lines changed: 14 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -19,18 +19,18 @@ func internalScripting(l *wrapper, d trace.Detailer) (t trace.Scripting) {
1919
return nil
2020
}
2121
ctx := with(*info.Context, TRACE, "ydb", "scripting", "execute")
22-
l.Log(ctx, "start")
22+
l.Log(ctx, "ydb starting script executing...")
2323
start := time.Now()
2424

2525
return func(info trace.ScriptingExecuteDoneInfo) {
2626
if info.Error == nil {
27-
l.Log(ctx, "done",
27+
l.Log(ctx, "ydb start script done",
2828
kv.Latency(start),
2929
kv.Int("resultSetCount", info.Result.ResultSetCount()),
3030
kv.NamedError("resultSetError", info.Result.Err()),
3131
)
3232
} else {
33-
l.Log(WithLevel(ctx, ERROR), "failed",
33+
l.Log(WithLevel(ctx, ERROR), "ydb start script failed",
3434
kv.Error(info.Error),
3535
kv.Latency(start),
3636
kv.Version(),
@@ -43,17 +43,17 @@ func internalScripting(l *wrapper, d trace.Detailer) (t trace.Scripting) {
4343
return nil
4444
}
4545
ctx := with(*info.Context, TRACE, "ydb", "scripting", "explain")
46-
l.Log(ctx, "start")
46+
l.Log(ctx, "ydb starting script explain...")
4747
start := time.Now()
4848

4949
return func(info trace.ScriptingExplainDoneInfo) {
5050
if info.Error == nil {
51-
l.Log(ctx, "done",
51+
l.Log(ctx, "ydb script explain done",
5252
kv.Latency(start),
5353
kv.String("plan", info.Plan),
5454
)
5555
} else {
56-
l.Log(WithLevel(ctx, ERROR), "failed",
56+
l.Log(WithLevel(ctx, ERROR), "ydb script explain failed",
5757
kv.Error(info.Error),
5858
kv.Latency(start),
5959
kv.Version(),
@@ -73,7 +73,7 @@ func internalScripting(l *wrapper, d trace.Detailer) (t trace.Scripting) {
7373
}
7474
ctx := with(*info.Context, TRACE, "ydb", "scripting", "stream", "execute")
7575
query := info.Query
76-
l.Log(ctx, "start",
76+
l.Log(ctx, "ydb script stream execute starting...",
7777
appendFieldByCondition(l.logQuery,
7878
kv.String("query", query),
7979
)...,
@@ -86,24 +86,24 @@ func internalScripting(l *wrapper, d trace.Detailer) (t trace.Scripting) {
8686
trace.ScriptingStreamExecuteDoneInfo,
8787
) {
8888
if info.Error == nil {
89-
l.Log(ctx, "intermediate")
89+
l.Log(ctx, "ydb script stream execute intermediate success")
9090
} else {
91-
l.Log(WithLevel(ctx, WARN), "intermediate failed",
91+
l.Log(WithLevel(ctx, WARN), "ydb script stream execute intermediate failed",
9292
kv.Error(info.Error),
9393
kv.Version(),
9494
)
9595
}
9696

9797
return func(info trace.ScriptingStreamExecuteDoneInfo) {
9898
if info.Error == nil {
99-
l.Log(ctx, "done",
99+
l.Log(ctx, "ydb script stream execute done",
100100
appendFieldByCondition(l.logQuery,
101101
kv.String("query", query),
102102
kv.Latency(start),
103103
)...,
104104
)
105105
} else {
106-
l.Log(WithLevel(ctx, ERROR), "failed",
106+
l.Log(WithLevel(ctx, ERROR), "ydb script stream execute failed",
107107
appendFieldByCondition(l.logQuery,
108108
kv.String("query", query),
109109
kv.Error(info.Error),
@@ -120,16 +120,16 @@ func internalScripting(l *wrapper, d trace.Detailer) (t trace.Scripting) {
120120
return nil
121121
}
122122
ctx := with(*info.Context, TRACE, "ydb", "scripting", "close")
123-
l.Log(ctx, "start")
123+
l.Log(ctx, "ydb script close starting...")
124124
start := time.Now()
125125

126126
return func(info trace.ScriptingCloseDoneInfo) {
127127
if info.Error == nil {
128-
l.Log(ctx, "done",
128+
l.Log(ctx, "ydb script close done",
129129
kv.Latency(start),
130130
)
131131
} else {
132-
l.Log(WithLevel(ctx, WARN), "failed",
132+
l.Log(WithLevel(ctx, WARN), "ydb script close failed",
133133
kv.Error(info.Error),
134134
kv.Latency(start),
135135
kv.Version(),

‎log/sql.go‎

Lines changed: 36 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -25,18 +25,18 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
2525
return nil
2626
}
2727
ctx := with(*info.Context, TRACE, "ydb", "database", "sql", "connector", "connect")
28-
l.Log(ctx, "start")
28+
l.Log(ctx, "ydb sql database connect starting...")
2929
start := time.Now()
3030

3131
return func(info trace.DatabaseSQLConnectorConnectDoneInfo) {
3232
if info.Error == nil {
33-
l.Log(WithLevel(ctx, DEBUG), "connected",
33+
l.Log(WithLevel(ctx, DEBUG), "ydb sql database connect done",
3434
kv.Latency(start),
3535
kv.String("session_id", info.Session.ID()),
3636
kv.String("session_status", info.Session.Status()),
3737
)
3838
} else {
39-
l.Log(WithLevel(ctx, ERROR), "failed",
39+
l.Log(WithLevel(ctx, ERROR), "ydb sql database connect failed",
4040
kv.Error(info.Error),
4141
kv.Latency(start),
4242
kv.Version(),
@@ -50,16 +50,16 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
5050
return nil
5151
}
5252
ctx := with(*info.Context, TRACE, "ydb", "database", "sql", "conn", "ping")
53-
l.Log(ctx, "start")
53+
l.Log(ctx, "ydb sql database ping starting...")
5454
start := time.Now()
5555

5656
return func(info trace.DatabaseSQLConnPingDoneInfo) {
5757
if info.Error == nil {
58-
l.Log(ctx, "done",
58+
l.Log(ctx, "ydb sql database ping done",
5959
kv.Latency(start),
6060
)
6161
} else {
62-
l.Log(WithLevel(ctx, ERROR), "failed",
62+
l.Log(WithLevel(ctx, ERROR), "ydb sql database ping failed",
6363
kv.Error(info.Error),
6464
kv.Latency(start),
6565
kv.Version(),
@@ -72,16 +72,16 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
7272
return nil
7373
}
7474
ctx := with(context.Background(), TRACE, "ydb", "database", "sql", "conn", "close")
75-
l.Log(ctx, "start")
75+
l.Log(ctx, "ydb sql connection close starting...")
7676
start := time.Now()
7777

7878
return func(info trace.DatabaseSQLConnCloseDoneInfo) {
7979
if info.Error == nil {
80-
l.Log(ctx, "done",
80+
l.Log(ctx, "ydb sql connection close done",
8181
kv.Latency(start),
8282
)
8383
} else {
84-
l.Log(WithLevel(ctx, WARN), "failed",
84+
l.Log(WithLevel(ctx, WARN), "ydb sql connection close failed",
8585
kv.Error(info.Error),
8686
kv.Latency(start),
8787
kv.Version(),
@@ -94,16 +94,16 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
9494
return nil
9595
}
9696
ctx := with(*info.Context, TRACE, "ydb", "database", "sql", "conn", "begin", "tx")
97-
l.Log(ctx, "start")
97+
l.Log(ctx, "ydb sql transaction begin starting...")
9898
start := time.Now()
9999

100100
return func(info trace.DatabaseSQLConnBeginDoneInfo) {
101101
if info.Error == nil {
102-
l.Log(ctx, "done",
102+
l.Log(ctx, "ydb sql transaction begin done",
103103
kv.Latency(start),
104104
)
105105
} else {
106-
l.Log(WithLevel(ctx, ERROR), "failed",
106+
l.Log(WithLevel(ctx, ERROR), "ydb sql transaction begin failed",
107107
kv.Error(info.Error),
108108
kv.Latency(start),
109109
kv.Version(),
@@ -116,7 +116,7 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
116116
return nil
117117
}
118118
ctx := with(*info.Context, TRACE, "ydb", "database", "sql", "conn", "prepare", "stmt")
119-
l.Log(ctx, "start",
119+
l.Log(ctx, "ydb sql prepare starting...",
120120
appendFieldByCondition(l.logQuery,
121121
kv.String("query", info.Query),
122122
)...,
@@ -126,11 +126,11 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
126126

127127
return func(info trace.DatabaseSQLConnPrepareDoneInfo) {
128128
if info.Error == nil {
129-
l.Log(ctx, "done",
129+
l.Log(ctx, "ydb sql prepare done",
130130
kv.Latency(start),
131131
)
132132
} else {
133-
l.Log(WithLevel(ctx, ERROR), "failed",
133+
l.Log(WithLevel(ctx, ERROR), "ydb sql prepare failed",
134134
appendFieldByCondition(l.logQuery,
135135
kv.String("query", query),
136136
kv.Error(info.Error),
@@ -146,7 +146,7 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
146146
return nil
147147
}
148148
ctx := with(*info.Context, TRACE, "ydb", "database", "sql", "conn", "exec")
149-
l.Log(ctx, "start",
149+
l.Log(ctx, "ydb sql exec starting...",
150150
appendFieldByCondition(l.logQuery,
151151
kv.String("query", info.Query),
152152
)...,
@@ -157,12 +157,12 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
157157

158158
return func(info trace.DatabaseSQLConnExecDoneInfo) {
159159
if info.Error == nil {
160-
l.Log(ctx, "done",
160+
l.Log(ctx, "ydb sql exec done",
161161
kv.Latency(start),
162162
)
163163
} else {
164164
m := retry.Check(info.Error)
165-
l.Log(WithLevel(ctx, ERROR), "failed",
165+
l.Log(WithLevel(ctx, ERROR), "ydb sql exec failed",
166166
appendFieldByCondition(l.logQuery,
167167
kv.String("query", query),
168168
kv.Bool("retryable", m.MustRetry(idempotent)),
@@ -181,7 +181,7 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
181181
return nil
182182
}
183183
ctx := with(*info.Context, TRACE, "ydb", "database", "sql", "conn", "query")
184-
l.Log(ctx, "start",
184+
l.Log(ctx, "ydb sql query starting...",
185185
appendFieldByCondition(l.logQuery,
186186
kv.String("query", info.Query),
187187
)...,
@@ -192,12 +192,12 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
192192

193193
return func(info trace.DatabaseSQLConnQueryDoneInfo) {
194194
if info.Error == nil {
195-
l.Log(ctx, "done",
195+
l.Log(ctx, "ydb sql query done",
196196
kv.Latency(start),
197197
)
198198
} else {
199199
m := retry.Check(info.Error)
200-
l.Log(WithLevel(ctx, ERROR), "failed",
200+
l.Log(WithLevel(ctx, ERROR), "ydb sql query failed",
201201
appendFieldByCondition(l.logQuery,
202202
kv.String("query", query),
203203
kv.Bool("retryable", m.MustRetry(idempotent)),
@@ -216,16 +216,16 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
216216
return nil
217217
}
218218
ctx := with(*info.Context, TRACE, "ydb", "database", "sql", "tx", "commit")
219-
l.Log(ctx, "start")
219+
l.Log(ctx, "ydb sql tx commit starting")
220220
start := time.Now()
221221

222222
return func(info trace.DatabaseSQLTxCommitDoneInfo) {
223223
if info.Error == nil {
224-
l.Log(ctx, "committed",
224+
l.Log(ctx, "ydb sql tx commit done",
225225
kv.Latency(start),
226226
)
227227
} else {
228-
l.Log(WithLevel(ctx, ERROR), "failed",
228+
l.Log(WithLevel(ctx, ERROR), "ydb sql tx commit failed",
229229
kv.Error(info.Error),
230230
kv.Latency(start),
231231
kv.Version(),
@@ -238,16 +238,16 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
238238
return nil
239239
}
240240
ctx := with(*info.Context, TRACE, "ydb", "database", "sql", "tx", "rollback")
241-
l.Log(ctx, "start")
241+
l.Log(ctx, "ydb sql tx rollback starting...")
242242
start := time.Now()
243243

244244
return func(info trace.DatabaseSQLTxRollbackDoneInfo) {
245245
if info.Error == nil {
246-
l.Log(ctx, "done",
246+
l.Log(ctx, "ydb sql tx rollback done",
247247
kv.Latency(start),
248248
)
249249
} else {
250-
l.Log(WithLevel(ctx, WARN), "failed",
250+
l.Log(WithLevel(ctx, WARN), "ydb sql tx rollback failed",
251251
kv.Error(info.Error),
252252
kv.Latency(start),
253253
kv.Version(),
@@ -260,16 +260,16 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
260260
return nil
261261
}
262262
ctx := with(context.Background(), TRACE, "ydb", "database", "sql", "stmt", "close")
263-
l.Log(ctx, "start")
263+
l.Log(ctx, "ydb sql statement close starting...")
264264
start := time.Now()
265265

266266
return func(info trace.DatabaseSQLStmtCloseDoneInfo) {
267267
if info.Error == nil {
268-
l.Log(ctx, "closed",
268+
l.Log(ctx, "ydb sql statement close done",
269269
kv.Latency(start),
270270
)
271271
} else {
272-
l.Log(WithLevel(ctx, ERROR), "close failed",
272+
l.Log(WithLevel(ctx, ERROR), "ydb sql statement close failed",
273273
kv.Error(info.Error),
274274
kv.Latency(start),
275275
kv.Version(),
@@ -282,7 +282,7 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
282282
return nil
283283
}
284284
ctx := with(*info.Context, TRACE, "ydb", "database", "sql", "stmt", "exec")
285-
l.Log(ctx, "start",
285+
l.Log(ctx, "ydb sql statement exec starting...",
286286
appendFieldByCondition(l.logQuery,
287287
kv.String("query", info.Query),
288288
)...,
@@ -292,12 +292,12 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
292292

293293
return func(info trace.DatabaseSQLStmtExecDoneInfo) {
294294
if info.Error == nil {
295-
l.Log(ctx, "done",
295+
l.Log(ctx, "ydb sql statement exec done",
296296
kv.Error(info.Error),
297297
kv.Latency(start),
298298
)
299299
} else {
300-
l.Log(WithLevel(ctx, ERROR), "failed",
300+
l.Log(WithLevel(ctx, ERROR), "ydb sql statement exec failed",
301301
appendFieldByCondition(l.logQuery,
302302
kv.String("query", query),
303303
kv.Error(info.Error),
@@ -313,7 +313,7 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
313313
return nil
314314
}
315315
ctx := with(*info.Context, TRACE, "ydb", "database", "sql", "stmt", "query")
316-
l.Log(ctx, "start",
316+
l.Log(ctx, "ydb sql statement query starting...",
317317
appendFieldByCondition(l.logQuery,
318318
kv.String("query", info.Query),
319319
)...,
@@ -323,11 +323,11 @@ func internalDatabaseSQL(l *wrapper, d trace.Detailer) (t trace.DatabaseSQL) {
323323

324324
return func(info trace.DatabaseSQLStmtQueryDoneInfo) {
325325
if info.Error == nil {
326-
l.Log(ctx, "done",
326+
l.Log(ctx, "ydb sql statement query done",
327327
kv.Latency(start),
328328
)
329329
} else {
330-
l.Log(WithLevel(ctx, ERROR), "failed",
330+
l.Log(WithLevel(ctx, ERROR), "ydb sql statement query failed",
331331
appendFieldByCondition(l.logQuery,
332332
kv.String("query", query),
333333
kv.Error(info.Error),

0 commit comments

Comments
 (0)