1
1
#include " dsproxy.h"
2
2
#include " dsproxy_mon.h"
3
3
#include " root_cause.h"
4
+ #include < ydb/core/blobstorage/dsproxy/dsproxy_request_reporting.h>
4
5
#include < ydb/core/blobstorage/vdisk/common/vdisk_events.h>
5
6
#include < ydb/core/blobstorage/lwtrace_probes/blobstorage_probes.h>
7
+ #include < ydb/core/util/stlog.h>
6
8
#include < library/cpp/containers/stack_vector/stack_vec.h>
7
9
#include < library/cpp/digest/crc32c/crc32c.h>
8
10
#include < util/generic/set.h>
@@ -36,8 +38,7 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor<TBlobSt
36
38
TRootCause RootCauseTrack;
37
39
NLWTrace::TOrbit Orbit;
38
40
const TInstant Deadline;
39
- TInstant StartTime;
40
- TInstant StartTimePut;
41
+ TMonotonic StartTimePut;
41
42
ui32 RequestsSent = 0 ;
42
43
ui32 ResponsesReceived = 0 ;
43
44
ui32 GroupSize;
@@ -58,6 +59,7 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor<TBlobSt
58
59
bool IsPutAccelerateScheduled = false ;
59
60
60
61
TAccelerationParams AccelerationParams;
62
+ TDuration LongRequestThreshold;
61
63
62
64
void Handle (TEvAccelerateGet::TPtr &ev) {
63
65
IsGetAccelerateScheduled = false ;
@@ -77,6 +79,7 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor<TBlobSt
77
79
}
78
80
GetsAccelerated++;
79
81
82
+ GetImpl.History .AddAcceleration (false );
80
83
TDeque<std::unique_ptr<TEvBlobStorage::TEvVGet>> vGets;
81
84
TDeque<std::unique_ptr<TEvBlobStorage::TEvVPut>> vPuts;
82
85
GetImpl.AccelerateGet (LogCtx, GetUnresponsiveDisksMask (), vGets, vPuts);
@@ -92,6 +95,7 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor<TBlobSt
92
95
}
93
96
PutsAccelerated++;
94
97
98
+ GetImpl.History .AddAcceleration (true );
95
99
TDeque<std::unique_ptr<TEvBlobStorage::TEvVGet>> vGets;
96
100
TDeque<std::unique_ptr<TEvBlobStorage::TEvVPut>> vPuts;
97
101
GetImpl.AcceleratePut (LogCtx, GetUnresponsiveDisksMask (), vGets, vPuts);
@@ -109,7 +113,7 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor<TBlobSt
109
113
if (vPuts.size ()) {
110
114
if (!IsPutStarted) {
111
115
IsPutStarted = true ;
112
- StartTimePut = TActivationContext::Now ();
116
+ StartTimePut = TActivationContext::Monotonic ();
113
117
}
114
118
}
115
119
for (size_t i = 0 ; i < vGets.size (); ++i) {
@@ -140,6 +144,7 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor<TBlobSt
140
144
}
141
145
SendToQueues (vGets, false );
142
146
SendToQueues (vPuts, false );
147
+ GetImpl.History .AddAllWaiting ();
143
148
}
144
149
145
150
ui32 CountDisksWithActiveRequests () {
@@ -319,8 +324,8 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor<TBlobSt
319
324
if (CountDisksWithActiveRequests () <= AccelerationParams.MaxNumOfSlowDisks ) {
320
325
ui64 timeToAccelerateUs = GetImpl.GetTimeToAccelerateGetNs (LogCtx) / 1000 ;
321
326
TDuration timeToAccelerate = TDuration::MicroSeconds (timeToAccelerateUs);
322
- TInstant now = TActivationContext::Now ();
323
- TInstant nextAcceleration = StartTime + timeToAccelerate;
327
+ TMonotonic now = TActivationContext::Monotonic ();
328
+ TMonotonic nextAcceleration = RequestStartTime + timeToAccelerate;
324
329
if (nextAcceleration > now) {
325
330
ui64 causeIdx = RootCauseTrack.RegisterAccelerate ();
326
331
Schedule (nextAcceleration - now, new TEvAccelerateGet (causeIdx));
@@ -338,8 +343,8 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor<TBlobSt
338
343
if (CountDisksWithActiveRequests () <= AccelerationParams.MaxNumOfSlowDisks ) {
339
344
ui64 timeToAccelerateUs = GetImpl.GetTimeToAcceleratePutNs (LogCtx) / 1000 ;
340
345
TDuration timeToAccelerate = TDuration::MicroSeconds (timeToAccelerateUs);
341
- TInstant now = TActivationContext::Now ();
342
- TInstant nextAcceleration = StartTime + timeToAccelerate;
346
+ TMonotonic now = TActivationContext::Monotonic ();
347
+ TMonotonic nextAcceleration = RequestStartTime + timeToAccelerate;
343
348
if (nextAcceleration > now) {
344
349
ui64 causeIdx = RootCauseTrack.RegisterAccelerate ();
345
350
Schedule (nextAcceleration - now, new TEvAcceleratePut (causeIdx));
@@ -352,9 +357,10 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor<TBlobSt
352
357
}
353
358
354
359
void SendReplyAndDie (TAutoPtr<TEvBlobStorage::TEvGetResult> &evResult) {
355
- const TInstant now = TActivationContext::Now ();
356
- const TDuration duration = (now > StartTime) ? (now - StartTime) : TDuration::MilliSeconds (0 );
357
- Mon->CountGetResponseTime (Info->GetDeviceType (), GetImpl.GetHandleClass (), evResult->PayloadSizeBytes (), duration);
360
+ const TMonotonic now = TActivationContext::Monotonic ();
361
+ const TDuration duration = now - RequestStartTime;
362
+ NKikimrBlobStorage::EGetHandleClass handleClass = GetImpl.GetHandleClass ();
363
+ Mon->CountGetResponseTime (Info->GetDeviceType (), handleClass, evResult->PayloadSizeBytes (), duration);
358
364
*Mon->ActiveGetCapacity -= ReportedBytes;
359
365
ReportedBytes = 0 ;
360
366
bool success = evResult->Status == NKikimrProto::OK;
@@ -370,9 +376,28 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor<TBlobSt
370
376
LWTRACK (DSProxyGetReply, Orbit);
371
377
evResult->Orbit = std::move (Orbit);
372
378
LWPROBE (DSProxyRequestDuration, TEvBlobStorage::EvGet, requestSize, duration.SecondsFloat () * 1000.0 , tabletId,
373
- evResult->GroupId , channel, NKikimrBlobStorage::EGetHandleClass_Name (GetImpl. GetHandleClass () ),
379
+ evResult->GroupId , channel, NKikimrBlobStorage::EGetHandleClass_Name (handleClass ),
374
380
success);
375
- A_LOG_LOG_S (true , success ? NLog::PRI_INFO : NLog::PRI_NOTICE, " BPG68" , " Result# " << evResult->Print (false ));
381
+ A_LOG_LOG_S (true , success ? NLog::PRI_INFO : NLog::PRI_NOTICE, " BPG68" , " Result# " << evResult->Print (false ) << " GroupId# " << Info->GroupID );
382
+
383
+ if (AllowToReport (handleClass)) {
384
+ if (TActivationContext::Monotonic () - RequestStartTime >= LongRequestThreshold) {
385
+ STLOG (PRI_WARN, BS_PROXY_GET, BPG71, " Long TEvGet request detected" , \
386
+ (LongRequestThreshold, LongRequestThreshold), \
387
+ (GroupId, Info->GroupID ), \
388
+ (SubrequestsCount, evResult->ResponseSz ), \
389
+ (RequestTotalSize, requestSize), \
390
+ (HandleClass, NKikimrBlobStorage::EGetHandleClass_Name (handleClass)), \
391
+ (RestartCounter, RestartCounter), \
392
+ (History, GetImpl.PrintHistory ()));
393
+ }
394
+
395
+ STLOG (GetImpl.WasNotOkResponses () ? NLog::PRI_NOTICE : NLog::PRI_DEBUG, BS_PROXY_GET, BPG72, \
396
+ " Query history" , \
397
+ (GroupId, Info->GroupID ), \
398
+ (HandleClass, NKikimrBlobStorage::EGetHandleClass_Name (handleClass)), \
399
+ (History, GetImpl.PrintHistory ()));
400
+ }
376
401
return SendResponseAndDie (std::unique_ptr<TEvBlobStorage::TEvGetResult>(evResult.Release ()));
377
402
}
378
403
@@ -401,11 +426,11 @@ class TBlobStorageGroupGetRequest : public TBlobStorageGroupRequestActor<TBlobSt
401
426
params.AccelerationParams, LogCtx.RequestPrefix)
402
427
, Orbit(std::move(params.Common.Event->Orbit))
403
428
, Deadline(params.Common.Event->Deadline)
404
- , StartTime(params.Common.Now)
405
- , StartTimePut(StartTime)
429
+ , StartTimePut(RequestStartTime)
406
430
, GroupSize(Info->Type.BlobSubgroupSize())
407
431
, ReportedBytes(0 )
408
432
, AccelerationParams(params.AccelerationParams)
433
+ , LongRequestThreshold(params.LongRequestThreshold)
409
434
{
410
435
ReportBytes (sizeof (*this ));
411
436
MaxSaneRequests = params.Common .Event ->QuerySize * Info->Type .TotalPartCount () *
0 commit comments