1 /* $Id: nc_stat.cpp 589151 2019-07-08 13:13:17Z gouriano $
2 * ===========================================================================
3 *
4 * PUBLIC DOMAIN NOTICE
5 * National Center for Biotechnology Information
6 *
7 * This software/database is a "United States Government Work" under the
8 * terms of the United States Copyright Act. It was written as part of
9 * the author's official duties as a United States Government employee and
10 * thus cannot be copyrighted. This software/database is freely available
11 * to the public for use. The National Library of Medicine and the U.S.
12 * Government have not placed any restriction on its use or reproduction.
13 *
14 * Although all reasonable efforts have been taken to ensure the accuracy
15 * and reliability of the software and data, the NLM and the U.S.
16 * Government do not and cannot warrant the performance or results that
17 * may be obtained by using this software or data. The NLM and the U.S.
18 * Government disclaim all warranties, express or implied, including
19 * warranties of performance, merchantability or fitness for any particular
20 * purpose.
21 *
22 * Please cite the author in any work or product based on this material.
23 *
24 * ===========================================================================
25 *
26 * Author: Pavel Ivanov
27 */
28
29 #include "nc_pch.hpp"
30
31 #include <corelib/request_ctx.hpp>
32
33 #include "netcached.hpp"
34 #include "nc_stat.hpp"
35 #include "distribution_conf.hpp"
36 #include "nc_storage.hpp"
37 #include "logging.hpp"
38 #include <set>
39
40
41 BEGIN_NCBI_SCOPE
42
43
44 static const Uint1 kCntStatPeriods = 10;
45 static const char* const kStatPeriodName[kCntStatPeriods]
46 = {"5s", "1min", "5min", "1h", "1d", "1w", "1mon", "3mon", "1y", "life"};
47 static Uint1 kCollectPeriodsCnt[kCntStatPeriods]
48 = {0, 12, 5, 12, 24, 7, 31, 3, 4, 0};
49 static const Uint1 kMinStatPeriod = 5;
50 static const Uint1 kDayPeriodIdx = 4;
51 static const Uint1 kMonthPeriodIdx = 6;
52 static const Uint1 kLifePeriodIdx = 9;
53
54
55 static CNCStat* s_ThreadStat = NULL;
56 static CNCStat** s_CurPeriodStat = NULL;
57 static CNCStat** s_PrevPeriodStat = NULL;
58 static CStatRotator* s_Rotator = NULL;
59 static CMiniMutex s_RotateLock;
60 static Uint1 s_PeriodsCollected[kCntStatPeriods] = {0};
61 static int s_LastRotateSecs = 0;
62
63 static CMiniMutex s_CommonStatLock;
64 static set<Uint8> s_SyncSrv;
65 static set<Uint8> s_UnknownSrv;
66 typedef map<Uint8, CSrvTime> TSyncTimes;
67 static TSyncTimes s_SyncSucceeded;
68 static TSyncTimes s_SyncFailed;
69
70 #define USE_DETAILED_SLOT_STAT 1
71 #if USE_DETAILED_SLOT_STAT
72 typedef map<Uint8, map<Uint2, CSrvTime> > TDetailedSyncTimes;
73 static TDetailedSyncTimes s_SyncPeriodic;
74 #else
75 static TSyncTimes s_SyncPeriodic;
76 #endif
77
78
79 static void
s_InitPeriodsCollected(void)80 s_InitPeriodsCollected(void)
81 {
82 #ifdef NCBI_OS_LINUX
83 time_t cur_secs = CSrvTime::CurSecs();
84 time_t adj_secs = cur_secs + CSrvTime::TZAdjustment();
85 struct tm t;
86 gmtime_r(&adj_secs, &t);
87 s_PeriodsCollected[1] = t.tm_sec / kMinStatPeriod;
88 s_PeriodsCollected[2] = t.tm_min % 5;
89 s_PeriodsCollected[3] = t.tm_min / 5;
90 s_PeriodsCollected[4] = t.tm_hour;
91 s_PeriodsCollected[5] = t.tm_wday;
92 s_PeriodsCollected[6] = t.tm_mday - 1;
93 s_PeriodsCollected[7] = t.tm_mon % 3;
94 s_PeriodsCollected[8] = t.tm_mon / 3;
95 s_LastRotateSecs = cur_secs;
96 #endif
97 }
98
99 static void
s_CheckTZChange(void)100 s_CheckTZChange(void)
101 {
102 #ifdef NCBI_OS_LINUX
103 time_t cur_secs = CSrvTime::CurSecs() + CSrvTime::TZAdjustment();
104 struct tm t;
105 gmtime_r(&cur_secs, &t);
106 s_PeriodsCollected[kDayPeriodIdx] = t.tm_hour;
107 #endif
108 }
109
110 static void
s_SetCurMonthSize(void)111 s_SetCurMonthSize(void)
112 {
113 #ifdef NCBI_OS_LINUX
114 time_t cur_secs = CSrvTime::CurSecs() + CSrvTime::TZAdjustment();
115 struct tm t;
116 gmtime_r(&cur_secs, &t);
117 if (t.tm_mon == 1) {
118 ++t.tm_mon;
119 t.tm_hour = t.tm_min = t.tm_sec = 0;
120 t.tm_isdst = -1;
121 time_t next_loc_time = mktime(&t);
122 --next_loc_time;
123 localtime_r(&next_loc_time, &t);
124 kCollectPeriodsCnt[kMonthPeriodIdx] = t.tm_mday;
125 }
126 else {
127 switch (t.tm_mon) {
128 case 0:
129 case 2:
130 case 4:
131 case 6:
132 case 7:
133 case 9:
134 case 11:
135 kCollectPeriodsCnt[kMonthPeriodIdx] = 31;
136 break;
137 default:
138 kCollectPeriodsCnt[kMonthPeriodIdx] = 30;
139 break;
140 }
141 }
142 #endif
143 }
144
145
146 inline bool
operator ()(const char * left,const char * right) const147 SConstCharCompare::operator() (const char* left, const char* right) const
148 {
149 return NStr::strcmp(left, right) < 0;
150 }
151
152
153 static inline CNCStat*
s_Stat(void)154 s_Stat(void)
155 {
156 return &s_ThreadStat[CTaskServer::GetCurThreadNum()];
157 }
158
159 static unsigned int
s_SizeIndex(Uint8 size)160 s_SizeIndex(Uint8 size)
161 {
162 if (size <= 1)
163 return 0;
164 --size;
165 return g_GetLogBase2(size);
166 }
167
168 void
AddSyncServer(Uint8 srv_id)169 CNCStat::AddSyncServer(Uint8 srv_id)
170 {
171 CMiniMutexGuard guard(s_CommonStatLock);
172 s_SyncSrv.insert(srv_id);
173 }
174
AddUnknownServer(Uint8 srv_id)175 bool CNCStat::AddUnknownServer(Uint8 srv_id)
176 {
177 CMiniMutexGuard guard(s_CommonStatLock);
178 if (s_UnknownSrv.find(srv_id) == s_UnknownSrv.end()) {
179 s_UnknownSrv.insert(srv_id);
180 return true;
181 }
182 return false;
183 }
184
185 void
InitialSyncDone(Uint8 srv_id,bool succeeded)186 CNCStat::InitialSyncDone(Uint8 srv_id, bool succeeded)
187 {
188 CMiniMutexGuard guard(s_CommonStatLock);
189 if (succeeded) {
190 s_SyncSucceeded[srv_id] = CSrvTime::Current();
191 } else {
192 s_SyncFailed[srv_id] = CSrvTime::Current();
193 }
194 }
195
196 void
Initialize(void)197 CNCStat::Initialize(void)
198 {
199 s_ThreadStat = new CNCStat[CTaskServer::GetMaxRunningThreads()];
200 s_CurPeriodStat = (CNCStat**)malloc(kCntStatPeriods * sizeof(CNCStat*));
201 s_PrevPeriodStat = (CNCStat**)malloc(kCntStatPeriods * sizeof(CNCStat*));
202 for (Uint1 i = 0; i < kCntStatPeriods; ++i) {
203 CNCStat* stat = new CNCStat();
204 stat->AddReference();
205 stat->InitStartState();
206 s_CurPeriodStat[i] = stat;
207
208 stat = new CNCStat();
209 stat->AddReference();
210 stat->InitStartState();
211 s_PrevPeriodStat[i] = stat;
212 }
213
214 s_InitPeriodsCollected();
215 s_SetCurMonthSize();
216
217 s_Rotator = new CStatRotator();
218 s_Rotator->CalcNextRun();
219 }
220
CNCStat(void)221 CNCStat::CNCStat(void)
222 : m_SrvStat(new CSrvStat())
223 {
224 x_ClearStats();
225 }
226
227 void
x_ClearStats(void)228 CNCStat::x_ClearStats(void)
229 {
230 m_StartedCmds = 0;
231 m_ClDataWrite = 0;
232 m_ClDataRead = 0;
233 m_PeerDataWrite = 0;
234 m_PeerDataRead = 0;
235 m_DiskDataWrite = 0;
236 m_DiskDataRead = 0;
237 m_MaxBlobSize = 0;
238 m_ClWrBlobs = 0;
239 m_ClWrBlobSize = 0;
240 m_ClWrLenBySize.resize(40);
241 m_ClRbackBlobs = 0;
242 m_ClRbackSize = 0;
243 m_ClRdBlobs = 0;
244 m_ClRdBlobSize = 0;
245 m_ClRdLenBySize.resize(40);
246 m_DiskWrBlobs = 0;
247 m_DiskWrBlobSize = 0;
248 m_DiskWrBySize.resize(0);
249 m_DiskWrBySize.resize(40, 0);
250 m_PeerSyncs = 0;
251 m_PeerSynOps = 0;
252 m_CntCleanedFiles = 0;
253 m_CntFailedFiles = 0;
254 m_CmdLens.Initialize();
255 m_CmdsByName.clear();
256 m_LensByStatus.clear();
257 m_ConnCmds.Initialize();
258 for (int i = 0; i < 40; ++i) {
259 m_ClWrLenBySize[i].Initialize();
260 m_ClRdLenBySize[i].Initialize();
261 }
262 m_CheckedRecs.Initialize();
263 m_MovedRecs.Initialize();
264 m_MovedSize.Initialize();
265 m_CntFiles.Initialize();
266 m_DBSize.Initialize();
267 m_GarbageSize.Initialize();
268 m_CntBlobs.Initialize();
269 m_CntKeys.Initialize();
270 m_MirrorActiveConns.Initialize();
271 m_MirrorBGConns.Initialize();
272 m_MirrorQSize.Initialize();
273 m_SyncLogSize.Initialize();
274 m_WBMemSize.Initialize();
275 m_WBReleasable.Initialize();
276 m_WBReleasing.Initialize();
277 }
278
279 void
InitStartState(void)280 CNCStat::InitStartState(void)
281 {
282 m_StartState.state_time = CSrvTime::Current();
283 m_StartState.progress_cmds = 0;
284 CNCServer::ReadCurState(m_StartState);
285 m_EndState = m_StartState;
286 m_SrvStat->InitStartState();
287 }
288
289 void
TransferEndState(CNCStat * src_stat)290 CNCStat::TransferEndState(CNCStat* src_stat)
291 {
292 src_stat->m_StatLock.Lock();
293 m_EndState = m_StartState = src_stat->m_EndState;
294 m_SrvStat->TransferEndState(src_stat->m_SrvStat.get());
295 src_stat->m_StatLock.Unlock();
296 }
297
298 void
x_CopyStartState(CNCStat * src_stat)299 CNCStat::x_CopyStartState(CNCStat* src_stat)
300 {
301 m_StartState = src_stat->m_StartState;
302 m_SrvStat->CopyStartState(src_stat->m_SrvStat.get());
303 }
304
305 void
x_CopyEndState(CNCStat * src_stat)306 CNCStat::x_CopyEndState(CNCStat* src_stat)
307 {
308 m_EndState = src_stat->m_EndState;
309 m_SrvStat->CopyEndState(src_stat->m_SrvStat.get());
310 }
311
312 void
x_SaveEndState(void)313 CNCStat::x_SaveEndState(void)
314 {
315 m_EndState.state_time = CSrvTime::Current();
316 m_EndState.progress_cmds = Uint4(m_StartState.progress_cmds
317 + m_StartedCmds - m_CmdLens.GetCount());
318 CNCServer::ReadCurState(m_EndState);
319 m_SrvStat->SaveEndState();
320 }
321
322 void
x_AddStats(CNCStat * src_stat)323 CNCStat::x_AddStats(CNCStat* src_stat)
324 {
325 m_StartedCmds += src_stat->m_StartedCmds;
326 m_CmdLens.AddValues(src_stat->m_CmdLens);
327 ITERATE(TCmdCountsMap, it, src_stat->m_CmdsByName) {
328 m_CmdsByName[it->first] += it->second;
329 }
330 ITERATE(TStatusCmdLens, it_stat, src_stat->m_LensByStatus) {
331 const TCmdLensMap& src_lens = it_stat->second;
332 TCmdLensMap& dst_lens = m_LensByStatus[it_stat->first];
333 ITERATE(TCmdLensMap, it_cmd, src_lens) {
334 TSrvTimeTerm& time_term = g_SrvTimeTerm(dst_lens, it_cmd->first);
335 time_term.AddValues(it_cmd->second);
336 }
337 }
338 m_ConnCmds.AddValues(src_stat->m_ConnCmds);
339 m_ClDataWrite += src_stat->m_ClDataWrite;
340 m_ClDataRead += src_stat->m_ClDataRead;
341 m_PeerDataWrite += src_stat->m_PeerDataWrite;
342 m_PeerDataRead += src_stat->m_PeerDataRead;
343 m_DiskDataWrite += src_stat->m_DiskDataWrite;
344 m_DiskDataRead += src_stat->m_DiskDataRead;
345 m_MaxBlobSize = max(m_MaxBlobSize, src_stat->m_MaxBlobSize);
346 m_ClWrBlobs += src_stat->m_ClWrBlobs;
347 m_ClWrBlobSize += src_stat->m_ClWrBlobSize;
348 for (size_t i = 0; i < src_stat->m_ClWrLenBySize.size(); ++i) {
349 m_ClWrLenBySize[i].AddValues(src_stat->m_ClWrLenBySize[i]);
350 m_ClRdLenBySize[i].AddValues(src_stat->m_ClRdLenBySize[i]);
351 m_DiskWrBySize[i] += src_stat->m_DiskWrBySize[i];
352 }
353 m_ClRbackBlobs += src_stat->m_ClRbackBlobs;
354 m_ClRbackSize += src_stat->m_ClRbackSize;
355 m_ClRdBlobs += src_stat->m_ClRdBlobs;
356 m_ClRdBlobSize += src_stat->m_ClRdBlobSize;
357 m_DiskWrBlobs += src_stat->m_DiskWrBlobs;
358 m_DiskWrBlobSize += src_stat->m_DiskWrBlobSize;
359 m_PeerSyncs += src_stat->m_PeerSyncs;
360 m_PeerSynOps += src_stat->m_PeerSynOps;
361 m_CntCleanedFiles += src_stat->m_CntCleanedFiles;
362 m_CntFailedFiles += src_stat->m_CntFailedFiles;
363 m_CheckedRecs.AddValues(src_stat->m_CheckedRecs);
364 m_MovedRecs.AddValues(src_stat->m_MovedRecs);
365 m_MovedSize.AddValues(src_stat->m_MovedSize);
366 m_CntFiles.AddValues(src_stat->m_CntFiles);
367 m_DBSize.AddValues(src_stat->m_DBSize);
368 m_GarbageSize.AddValues(src_stat->m_GarbageSize);
369 m_CntBlobs.AddValues(src_stat->m_CntBlobs);
370 m_CntKeys.AddValues(src_stat->m_CntKeys);
371 m_MirrorActiveConns.AddValues(src_stat->m_MirrorActiveConns);
372 m_MirrorBGConns.AddValues(src_stat->m_MirrorBGConns);
373 m_MirrorQSize.AddValues(src_stat->m_MirrorQSize);
374 m_SyncLogSize.AddValues(src_stat->m_SyncLogSize);
375 m_WBMemSize.AddValues(src_stat->m_WBMemSize);
376 m_WBReleasable.AddValues(src_stat->m_WBReleasable);
377 m_WBReleasing.AddValues(src_stat->m_WBReleasing);
378 }
379
380 void
AddAllStats(CNCStat * src_stat)381 CNCStat::AddAllStats(CNCStat* src_stat)
382 {
383 m_StatLock.Lock();
384 src_stat->m_StatLock.Lock();
385
386 x_AddStats(src_stat);
387 m_SrvStat->AddAllStats(src_stat->m_SrvStat.get());
388 x_CopyEndState(src_stat);
389
390 src_stat->m_StatLock.Unlock();
391 m_StatLock.Unlock();
392 }
393
394 void
CollectThreads(CNCStat * dst_stat,bool need_clear)395 CNCStat::CollectThreads(CNCStat* dst_stat, bool need_clear)
396 {
397 dst_stat->m_StatLock.Lock();
398 TSrvThreadNum cnt_threads = CTaskServer::GetMaxRunningThreads();
399 for (TSrvThreadNum i = 0; i < cnt_threads; ++i) {
400 CNCStat* src_stat = &s_ThreadStat[i];
401 src_stat->m_StatLock.Lock();
402 dst_stat->x_AddStats(src_stat);
403 if (need_clear)
404 src_stat->x_ClearStats();
405 src_stat->m_StatLock.Unlock();
406 }
407 dst_stat->m_SrvStat->CollectThreads(need_clear);
408 dst_stat->x_SaveEndState();
409 dst_stat->m_StatLock.Unlock();
410 }
411
412 CSrvRef<CNCStat>
GetStat(const string & stat_type,bool is_prev)413 CNCStat::GetStat(const string& stat_type, bool is_prev)
414 {
415 Uint1 idx = 0;
416 while (idx < kCntStatPeriods && kStatPeriodName[idx] != stat_type)
417 ++idx;
418 if (idx >= kCntStatPeriods)
419 return CSrvRef<CNCStat>();
420
421 CSrvRef<CNCStat> stat;
422 s_RotateLock.Lock();
423 if (is_prev)
424 stat = s_PrevPeriodStat[idx];
425 else
426 stat = s_CurPeriodStat[idx];
427 stat->m_StatName = stat_type;
428 s_RotateLock.Unlock();
429
430 if (is_prev)
431 return stat;
432
433 CSrvRef<CNCStat> stat_copy(new CNCStat());
434 stat_copy->m_StatName = stat_type;
435 stat_copy->x_CopyStartState(stat);
436 stat_copy->AddAllStats(stat);
437 CollectThreads(stat_copy, false);
438
439 return stat_copy;
440 }
441
442 Uint4
GetCntRunningCmds(void)443 CNCStat::GetCntRunningCmds(void)
444 {
445 s_RotateLock.Lock();
446 CNCStat* stat = s_CurPeriodStat[0];
447 Uint8 cnt_cmds = stat->m_StartState.progress_cmds
448 + stat->m_StartedCmds - stat->m_CmdLens.GetCount();
449 s_RotateLock.Unlock();
450
451 TSrvThreadNum cnt_threads = CTaskServer::GetMaxRunningThreads();
452 for (TSrvThreadNum i = 0; i < cnt_threads; ++i) {
453 stat = &s_ThreadStat[i];
454 stat->m_StatLock.Lock();
455 cnt_cmds += stat->m_StartedCmds;
456 cnt_cmds -= stat->m_CmdLens.GetCount();
457 stat->m_StatLock.Unlock();
458 }
459
460 return Uint4(cnt_cmds);
461 }
462
463 void
CmdStarted(const char * cmd)464 CNCStat::CmdStarted(const char* cmd)
465 {
466 CNCStat* stat = s_Stat();
467 stat->m_StatLock.Lock();
468 ++stat->m_StartedCmds;
469 ++stat->m_CmdsByName[cmd];
470 stat->m_StatLock.Unlock();
471 }
472
473 void
CmdFinished(const char * cmd,Uint8 len_usec,int status)474 CNCStat::CmdFinished(const char* cmd, Uint8 len_usec, int status)
475 {
476 CNCStat* stat = s_Stat();
477 stat->m_StatLock.Lock();
478 stat->m_CmdLens.AddValue(len_usec);
479 TCmdLensMap& cmd_lens = stat->m_LensByStatus[status];
480 TSrvTimeTerm& time_term = g_SrvTimeTerm(cmd_lens, cmd);
481 time_term.AddValue(len_usec);
482 stat->m_StatLock.Unlock();
483 }
484
485 void
ConnClosing(Uint8 cnt_cmds)486 CNCStat::ConnClosing(Uint8 cnt_cmds)
487 {
488 CNCStat* stat = s_Stat();
489 stat->m_StatLock.Lock();
490 stat->m_ConnCmds.AddValue(cnt_cmds);
491 stat->m_StatLock.Unlock();
492 }
493
494 void
ClientDataWrite(size_t data_size)495 CNCStat::ClientDataWrite(size_t data_size)
496 {
497 AtomicAdd(s_Stat()->m_ClDataWrite, data_size);
498 }
499
500 void
ClientDataRead(size_t data_size)501 CNCStat::ClientDataRead(size_t data_size)
502 {
503 AtomicAdd(s_Stat()->m_ClDataRead, data_size);
504 }
505
506 void
ClientBlobWrite(Uint8 blob_size,Uint8 len_usec)507 CNCStat::ClientBlobWrite(Uint8 blob_size, Uint8 len_usec)
508 {
509 CNCStat* stat = s_Stat();
510 stat->m_StatLock.Lock();
511 ++stat->m_ClWrBlobs;
512 stat->m_ClWrBlobSize += blob_size;
513 stat->m_MaxBlobSize = max(stat->m_MaxBlobSize, blob_size);
514 Uint4 size_idx = s_SizeIndex(blob_size);
515 stat->m_ClWrLenBySize[size_idx].AddValue(len_usec);
516 stat->m_StatLock.Unlock();
517 }
518
519 void
ClientBlobRollback(Uint8 written_size)520 CNCStat::ClientBlobRollback(Uint8 written_size)
521 {
522 CNCStat* stat = s_Stat();
523 AtomicAdd(stat->m_ClRbackBlobs, 1);
524 AtomicAdd(stat->m_ClRbackSize, written_size);
525 }
526
527 void
ClientBlobRead(Uint8 blob_size,Uint8 len_usec)528 CNCStat::ClientBlobRead(Uint8 blob_size, Uint8 len_usec)
529 {
530 CNCStat* stat = s_Stat();
531 stat->m_StatLock.Lock();
532 ++stat->m_ClRdBlobs;
533 stat->m_ClRdBlobSize += blob_size;
534 stat->m_MaxBlobSize = max(stat->m_MaxBlobSize, blob_size);
535 Uint4 size_idx = s_SizeIndex(blob_size);
536 stat->m_ClRdLenBySize[size_idx].AddValue(len_usec);
537 stat->m_StatLock.Unlock();
538 }
539
540 void
PeerDataWrite(size_t data_size)541 CNCStat::PeerDataWrite(size_t data_size)
542 {
543 AtomicAdd(s_Stat()->m_PeerDataWrite, data_size);
544 }
545
546 void
PeerDataRead(size_t data_size)547 CNCStat::PeerDataRead(size_t data_size)
548 {
549 AtomicAdd(s_Stat()->m_PeerDataRead, data_size);
550 }
551
552 void
PeerSyncFinished(Uint8 srv_id,Uint2 slot,Uint8 cnt_ops,bool success)553 CNCStat::PeerSyncFinished(Uint8 srv_id, Uint2 slot, Uint8 cnt_ops, bool success)
554 {
555 CNCStat* stat = s_Stat();
556 if (success)
557 AtomicAdd(stat->m_PeerSyncs, 1);
558 AtomicAdd(stat->m_PeerSynOps, cnt_ops);
559 if (success) {
560 CMiniMutexGuard guard(s_CommonStatLock);
561 #if USE_DETAILED_SLOT_STAT
562 s_SyncPeriodic[srv_id][slot] = CSrvTime::Current();
563 #else
564 s_SyncPeriodic[srv_id] = CSrvTime::Current();
565 #endif
566 }
567 }
568
569 void
DiskDataWrite(size_t data_size)570 CNCStat::DiskDataWrite(size_t data_size)
571 {
572 AtomicAdd(s_Stat()->m_DiskDataWrite, data_size);
573 }
574
575 void
DiskDataRead(size_t data_size)576 CNCStat::DiskDataRead(size_t data_size)
577 {
578 AtomicAdd(s_Stat()->m_DiskDataRead, data_size);
579 }
580
581 void
DiskBlobWrite(Uint8 blob_size)582 CNCStat::DiskBlobWrite(Uint8 blob_size)
583 {
584 CNCStat* stat = s_Stat();
585 stat->m_StatLock.Lock();
586 ++stat->m_DiskWrBlobs;
587 stat->m_DiskWrBlobSize += blob_size;
588 stat->m_MaxBlobSize = max(stat->m_MaxBlobSize, blob_size);
589 ++stat->m_DiskWrBySize[s_SizeIndex(blob_size)];
590 stat->m_StatLock.Unlock();
591 }
592
593 void
DBFileCleaned(bool success,Uint4 seen_recs,Uint4 moved_recs,Uint4 moved_size)594 CNCStat::DBFileCleaned(bool success, Uint4 seen_recs,
595 Uint4 moved_recs, Uint4 moved_size)
596 {
597 CNCStat* stat = s_Stat();
598 stat->m_StatLock.Lock();
599 if (success)
600 ++stat->m_CntCleanedFiles;
601 else
602 ++stat->m_CntFailedFiles;
603 stat->m_CheckedRecs.AddValue(seen_recs);
604 stat->m_MovedRecs.AddValue(moved_recs);
605 stat->m_MovedSize.AddValue(moved_size);
606 stat->m_StatLock.Unlock();
607 }
608
609 void
SaveCurStateStat(const SNCStateStat & state)610 CNCStat::SaveCurStateStat(const SNCStateStat& state)
611 {
612 CNCStat* stat = s_Stat();
613 stat->m_StatLock.Lock();
614 stat->m_CntFiles.AddValue(state.db_files);
615 stat->m_DBSize.AddValue(state.db_size);
616 stat->m_GarbageSize.AddValue(state.db_garb);
617 stat->m_CntBlobs.AddValue(state.cnt_blobs);
618 stat->m_CntKeys.AddValue(state.cnt_keys);
619 stat->m_MirrorActiveConns.AddValue(state.peer_active_conns);
620 stat->m_MirrorBGConns.AddValue(state.peer_bg_conns);
621 stat->m_MirrorQSize.AddValue(state.mirror_queue_size);
622 stat->m_SyncLogSize.AddValue(state.sync_log_size);
623 stat->m_WBMemSize.AddValue(state.wb_size);
624 stat->m_WBReleasable.AddValue(state.wb_releasable);
625 stat->m_WBReleasing.AddValue(state.wb_releasing);
626 stat->m_StatLock.Unlock();
627
628 CSrvRef<CNCStat> stat_5s = GetStat(kStatPeriodName[0], false);
629 stat_5s->m_SrvStat->SaveEndStateStat();
630 }
631
632 void
x_PrintUnstructured(CSrvPrintProxy & proxy)633 CNCStat::x_PrintUnstructured(CSrvPrintProxy& proxy)
634 {
635 if (m_CmdLens.GetCount() != 0) {
636 proxy << "Commands by status and type:" << endl;
637 ITERATE(TStatusCmdLens, it_st, m_LensByStatus) {
638 proxy << it_st->first << ":" << endl;
639 const TCmdLensMap& lens_map = it_st->second;
640 ITERATE(TCmdLensMap, it_cmd, lens_map) {
641 const TSrvTimeTerm& time_term = it_cmd->second;
642 proxy << it_cmd->first << " - "
643 << g_ToSmartStr(time_term.GetCount()) << " (cnt), "
644 << g_AsMSecStat(time_term.GetAverage()) << " (avg msec), "
645 << g_AsMSecStat(time_term.GetMaximum()) << " (max msec)" << endl;
646 }
647 }
648 proxy << endl;
649 }
650 if (m_ClWrBlobs != 0) {
651 proxy << "Client writes by size:" << endl;
652 Uint8 prev_size = 0, size = 2;
653 for (size_t i = 0; i < m_ClWrLenBySize.size() && prev_size < m_MaxBlobSize
654 ; ++i, prev_size = size + 1, size <<= 1)
655 {
656 if (m_ClWrLenBySize[i].GetCount() == 0)
657 continue;
658
659 TSrvTimeTerm& time_term = m_ClWrLenBySize[i];
660 proxy << g_ToSizeStr(prev_size) << "-" << g_ToSizeStr(size) << ": "
661 << g_ToSmartStr(time_term.GetCount()) << " (cnt), "
662 << g_AsMSecStat(time_term.GetAverage()) << " (avg msec), "
663 << g_AsMSecStat(time_term.GetMaximum()) << " (max msec)" << endl;
664 }
665 proxy << endl;
666 }
667 if (m_ClRdBlobs != 0) {
668 proxy << "Client reads by size:" << endl;
669 Uint8 prev_size = 0, size = 2;
670 for (size_t i = 0; i < m_ClRdLenBySize.size() && prev_size < m_MaxBlobSize
671 ; ++i, prev_size = size + 1, size <<= 1)
672 {
673 if (m_ClRdLenBySize[i].GetCount() == 0)
674 continue;
675
676 TSrvTimeTerm& time_term = m_ClRdLenBySize[i];
677 proxy << g_ToSizeStr(prev_size) << "-" << g_ToSizeStr(size) << ": "
678 << g_ToSmartStr(time_term.GetCount()) << " (cnt), "
679 << g_AsMSecStat(time_term.GetAverage()) << " (avg msec), "
680 << g_AsMSecStat(time_term.GetMaximum()) << " (max msec)" << endl;
681 }
682 proxy << endl;
683 }
684 if (m_DiskWrBlobs != 0) {
685 proxy << "Disk writes by size:" << endl;
686 Uint8 prev_size = 0, size = 2;
687 for (size_t i = 0; i < m_DiskWrBySize.size() && prev_size < m_MaxBlobSize
688 ; ++i, prev_size = size + 1, size <<= 1)
689 {
690 if (m_DiskWrBySize[i] != 0) {
691 proxy << g_ToSizeStr(prev_size) << "-" << g_ToSizeStr(size) << ": "
692 << g_ToSmartStr(m_DiskWrBySize[i]) << " (cnt)" << endl;
693 }
694 }
695 proxy << endl;
696 }
697 }
698
699 void
PrintToLogs(CTempString stat_name)700 CNCStat::PrintToLogs(CTempString stat_name)
701 {
702 char buf[50];
703 CSrvTime t;
704
705 m_StatLock.Lock();
706 CSrvRef<CRequestContext> ctx(new CRequestContext());
707 ctx->SetRequestID();
708 CSrvDiagMsg diag;
709 diag.StartRequest(ctx);
710 diag.PrintParam("_type", "stat").PrintParam("name", stat_name);
711 m_StartState.state_time.Print(buf, CSrvTime::eFmtLogging);
712 diag.PrintParam("start_time", buf);
713 m_EndState.state_time.Print(buf, CSrvTime::eFmtLogging);
714 diag.PrintParam("end_time", buf);
715 CSrvTime time_diff = m_EndState.state_time;
716 time_diff -= m_StartState.state_time;
717 Uint8 time_secs = time_diff.AsUSec() / kUSecsPerSecond;
718 if (time_secs == 0)
719 time_secs = 1;
720
721 diag.PrintParam("start_run_cmds", m_StartState.progress_cmds)
722 .PrintParam("end_run_cmds", m_EndState.progress_cmds)
723 .PrintParam("cmds_started", m_StartedCmds)
724 .PrintParam("cmds_finished", m_CmdLens.GetCount())
725 .PrintParam("avg_conn_cmds", m_ConnCmds.GetAverage())
726 .PrintParam("max_conn_cmds", m_ConnCmds.GetMaximum());
727 diag.PrintParam("start_db_size", m_StartState.db_size)
728 .PrintParam("end_db_size", m_EndState.db_size)
729 .PrintParam("avg_db_size", m_DBSize.GetAverage())
730 .PrintParam("max_db_size", m_DBSize.GetMaximum());
731 diag.PrintParam("start_garbage", m_StartState.db_garb)
732 .PrintParam("end_garbage", m_EndState.db_garb)
733 .PrintParam("avg_garbage", m_GarbageSize.GetAverage())
734 .PrintParam("max_garbage", m_GarbageSize.GetMaximum())
735 .PrintParam("start_garb_pct", g_CalcStatPct(m_StartState.db_garb, m_StartState.db_size))
736 .PrintParam("end_garb_pct", g_CalcStatPct(m_EndState.db_garb, m_EndState.db_size));
737 diag.PrintParam("start_db_files", m_StartState.db_files)
738 .PrintParam("end_db_files", m_EndState.db_files)
739 .PrintParam("avg_db_files", m_CntFiles.GetAverage())
740 .PrintParam("max_db_files", m_CntFiles.GetMaximum())
741 .PrintParam("start_blobs", m_StartState.cnt_blobs)
742 .PrintParam("end_blobs", m_EndState.cnt_blobs)
743 .PrintParam("avg_blobs", m_CntBlobs.GetAverage())
744 .PrintParam("max_blobs", m_CntBlobs.GetMaximum())
745 .PrintParam("start_keys", m_StartState.cnt_keys)
746 .PrintParam("end_keys", m_EndState.cnt_keys)
747 .PrintParam("avg_keys", m_CntKeys.GetAverage())
748 .PrintParam("max_keys", m_CntKeys.GetMaximum())
749 .PrintParam("start_peer_active_conns", m_StartState.peer_active_conns)
750 .PrintParam("end_peer_active_conns", m_EndState.peer_active_conns)
751 .PrintParam("avg_peer_active_conns", m_MirrorActiveConns.GetAverage())
752 .PrintParam("max_peer_active_conns", m_MirrorActiveConns.GetMaximum())
753 .PrintParam("start_peer_bg_conns", m_StartState.peer_bg_conns)
754 .PrintParam("end_peer_bg_conns", m_EndState.peer_bg_conns)
755 .PrintParam("avg_peer_bg_conns", m_MirrorBGConns.GetAverage())
756 .PrintParam("max_peer_bg_conns", m_MirrorBGConns.GetAverage())
757 .PrintParam("start_mirror_q_size", m_StartState.mirror_queue_size)
758 .PrintParam("end_mirror_q_size", m_EndState.mirror_queue_size)
759 .PrintParam("avg_mirror_q_size", m_MirrorQSize.GetAverage())
760 .PrintParam("max_mirror_q_size", m_MirrorQSize.GetMaximum())
761 .PrintParam("start_sync_log_size", m_StartState.sync_log_size)
762 .PrintParam("end_sync_log_size", m_EndState.sync_log_size)
763 .PrintParam("avg_sync_log_size", m_SyncLogSize.GetAverage())
764 .PrintParam("max_sync_log_size", m_SyncLogSize.GetMaximum());
765 diag.PrintParam("start_wb_size", m_StartState.wb_size)
766 .PrintParam("end_wb_size", m_EndState.wb_size)
767 .PrintParam("avg_wb_size", m_WBMemSize.GetAverage())
768 .PrintParam("max_wb_size", m_WBMemSize.GetMaximum())
769 .PrintParam("start_wb_releasable", m_StartState.wb_releasable)
770 .PrintParam("end_wb_releasable", m_EndState.wb_releasable)
771 .PrintParam("avg_wb_releasable", m_WBReleasable.GetAverage())
772 .PrintParam("max_wb_releasable", m_WBReleasable.GetMaximum())
773 .PrintParam("start_wb_releasing", m_StartState.wb_releasing)
774 .PrintParam("end_wb_releasing", m_EndState.wb_releasing)
775 .PrintParam("avg_wb_releasing", m_WBReleasing.GetAverage())
776 .PrintParam("max_wb_releasing", m_WBReleasing.GetMaximum());
777 if (m_StartState.min_dead_time != 0) {
778 t.Sec() = m_StartState.min_dead_time;
779 t.Print(buf, CSrvTime::eFmtLogging);
780 diag.PrintParam("start_dead", buf);
781 }
782 if (m_EndState.min_dead_time != 0) {
783 t.Sec() = m_EndState.min_dead_time;
784 t.Print(buf, CSrvTime::eFmtLogging);
785 diag.PrintParam("end_dead", buf);
786 }
787 diag.PrintParam("cl_write", m_ClDataWrite)
788 .PrintParam("avg_cl_write", m_ClDataWrite / time_secs)
789 .PrintParam("cl_read", m_ClDataRead)
790 .PrintParam("avg_cl_read", m_ClDataRead / time_secs)
791 .PrintParam("peer_write", m_PeerDataWrite)
792 .PrintParam("avg_peer_write", m_PeerDataWrite / time_secs)
793 .PrintParam("peer_read", m_PeerDataRead)
794 .PrintParam("avg_peer_read", m_PeerDataRead / time_secs)
795 .PrintParam("disk_write", m_DiskDataWrite)
796 .PrintParam("avg_disk_write", m_DiskDataWrite / time_secs)
797 .PrintParam("disk_read", m_DiskDataRead)
798 .PrintParam("avg_disk_read", m_DiskDataRead / time_secs);
799 diag.PrintParam("cl_wr_blobs", m_ClWrBlobs)
800 .PrintParam("cl_wr_avg_blobs", m_ClWrBlobs / time_secs)
801 .PrintParam("cl_wr_size", m_ClWrBlobSize)
802 .PrintParam("cl_rback_blobs", m_ClRbackBlobs)
803 .PrintParam("cl_rback_size", m_ClRbackSize)
804 .PrintParam("cl_rd_blobs", m_ClRdBlobs)
805 .PrintParam("cl_rd_avg_blobs", m_ClRdBlobs / time_secs)
806 .PrintParam("cl_rd_size", m_ClRdBlobSize)
807 .PrintParam("disk_wr_blobs", m_DiskWrBlobs)
808 .PrintParam("disk_wr_avg_blobs", m_DiskWrBlobs / time_secs)
809 .PrintParam("disk_wr_size", m_DiskWrBlobSize);
810 diag.PrintParam("peer_syncs", m_PeerSyncs)
811 .PrintParam("peer_syn_ops", m_PeerSynOps)
812 .PrintParam("cleaned_files", m_CntCleanedFiles)
813 .PrintParam("failed_cleans", m_CntFailedFiles)
814 .PrintParam("checked_recs", m_CheckedRecs.GetSum())
815 .PrintParam("avg_checked_recs", m_CheckedRecs.GetAverage())
816 .PrintParam("moved_recs", m_MovedRecs.GetSum())
817 .PrintParam("avg_moved_recs", m_MovedRecs.GetAverage())
818 .PrintParam("moved_size", m_MovedSize.GetSum())
819 .PrintParam("avg_moved_size", m_MovedSize.GetAverage());
820 diag.Flush();
821
822 CSrvPrintProxy proxy(ctx);
823 m_SrvStat->PrintToLogs(ctx, proxy);
824 // 13oct16: removed - nobody will see it anyway
825 // x_PrintUnstructured(proxy);
826
827 diag.StopRequest(ctx);
828 m_StatLock.Unlock();
829 }
830
PrintState(CSrvSocketTask & task)831 void CNCStat::PrintState(CSrvSocketTask& task)
832 {
833 string is("\": "), iss("\": \""), eol(",\n\""), str("_str");
834 task.WriteText(eol).WriteText("period" ).WriteText(iss).WriteText(m_StatName).WriteText("\"");
835
836 task.WriteText(eol).WriteText("progress_cmds" ).WriteText(is ).WriteNumber( m_EndState.progress_cmds);
837 task.WriteText(eol).WriteText("db_files" ).WriteText(is ).WriteNumber( m_EndState.db_files);
838 task.WriteText(eol).WriteText("db_size" ).WriteText(str).WriteText(iss)
839 .WriteText( NStr::UInt8ToString_DataSize( m_EndState.db_size)).WriteText("\"");
840 task.WriteText(eol).WriteText("db_size" ).WriteText(is ).WriteNumber( m_EndState.db_size);
841 task.WriteText(eol).WriteText("db_garb" ).WriteText(is ).WriteNumber( m_EndState.db_garb);
842 task.WriteText(eol).WriteText("cnt_blobs" ).WriteText(is ).WriteNumber( m_EndState.cnt_blobs);
843 task.WriteText(eol).WriteText("cnt_keys" ).WriteText(is ).WriteNumber( m_EndState.cnt_keys);
844 task.WriteText(eol).WriteText("peer_active_conns" ).WriteText(is ).WriteNumber( m_EndState.peer_active_conns);
845 task.WriteText(eol).WriteText("peer_bg_conns" ).WriteText(is ).WriteNumber( m_EndState.peer_bg_conns);
846 task.WriteText(eol).WriteText("mirror_queue_size" ).WriteText(is ).WriteNumber( m_EndState.mirror_queue_size);
847 task.WriteText(eol).WriteText("sync_log_size" ).WriteText(is ).WriteNumber( m_EndState.sync_log_size);
848 task.WriteText(eol).WriteText("wb_size" ).WriteText(str).WriteText(iss)
849 .WriteText(NStr::UInt8ToString_DataSize( m_EndState.wb_size)).WriteText("\"");
850 task.WriteText(eol).WriteText("wb_size" ).WriteText(is ).WriteNumber( m_EndState.wb_size);
851 task.WriteText(eol).WriteText("wb_releasable").WriteText(str).WriteText(iss)
852 .WriteText(NStr::UInt8ToString_DataSize( m_EndState.wb_releasable)).WriteText("\"");
853 task.WriteText(eol).WriteText("wb_releasable").WriteText(is ).WriteNumber( m_EndState.wb_releasable);
854 task.WriteText(eol).WriteText("wb_releasing" ).WriteText(str).WriteText(iss)
855 .WriteText(NStr::UInt8ToString_DataSize( m_EndState.wb_releasing)).WriteText("\"");
856 task.WriteText(eol).WriteText("wb_releasing" ).WriteText(is ).WriteNumber( m_EndState.wb_releasing);
857
858 task.WriteText(eol).WriteText("cnt_another_server_main" ).WriteText(is ).WriteNumber( m_EndState.cnt_another_server_main);
859 task.WriteText(eol).WriteText("avg_tdiff_blobcopy" ).WriteText(is ).WriteNumber( m_EndState.avg_tdiff_blobcopy);
860 task.WriteText(eol).WriteText("max_tdiff_blobcopy" ).WriteText(is ).WriteNumber( m_EndState.max_tdiff_blobcopy);
861 task.WriteText(eol).WriteText("avg_tdiff_blobnotify" ).WriteText(is ).WriteNumber( m_EndState.avg_tdiff_blobnotify);
862 task.WriteText(eol).WriteText("max_tdiff_blobnotify" ).WriteText(is ).WriteNumber( m_EndState.max_tdiff_blobnotify);
863 task.WriteText(eol).WriteText("log_visible").WriteText(iss).WriteText(GetLogVisibility()).WriteText("\"");
864 task.WriteText(eol).WriteText("soft_fatal_action").WriteText(iss).WriteText(GetSoftFatalAction()).WriteText("\"");
865 m_SrvStat->PrintState(task);
866 }
867
868 void
PrintToSocket(CSrvSocketTask * sock)869 CNCStat::PrintToSocket(CSrvSocketTask* sock)
870 {
871 m_StatLock.Lock();
872 CSrvPrintProxy proxy(sock);
873 char buf[50];
874 CSrvTime t;
875
876 proxy << "Stat type - " << m_StatName;
877 m_StartState.state_time.Print(buf, CSrvTime::eFmtHumanUSecs);
878 proxy << ", start " << buf;
879 m_EndState.state_time.Print(buf, CSrvTime::eFmtHumanUSecs);
880 proxy << ", end " << buf <<endl;
881 proxy << "PID - " << (Uint8)CCurrentProcess::GetPid() << endl;
882 if (CNCBlobStorage::IsDraining()) {
883 CSrvTime( CNCBlobStorage::GetLatestBlobExpire()).Print( buf, CSrvTime::eFmtHumanSeconds);
884 proxy << "Draining started, estimated end: " << buf << endl;
885 }
886 {
887 CMiniMutexGuard guard(s_CommonStatLock);
888 Uint8 now = CSrvTime::Current().AsUSec();
889 if (!s_SyncSrv.empty()) {
890 {
891 vector<string> t;
892 ITERATE(set<Uint8>, s, s_SyncSrv) {
893 string n(CNCDistributionConf::GetPeerNameOrEmpty(*s));
894 if (!n.empty()) {
895 t.push_back(n);
896 }
897 }
898 proxy << "Sync servers: " << NStr::Join(t,",") << endl;
899 }
900 ITERATE(TSyncTimes, s, s_SyncSucceeded) {
901 s->second.Print(buf, CSrvTime::eFmtHumanUSecs);
902 proxy << "Initial Sync succeeded - " <<
903 CNCDistributionConf::GetPeerName(s->first) << " at " << buf << endl;
904 }
905 if (!s_SyncFailed.empty()) {
906 ITERATE(TSyncTimes, s, s_SyncFailed) {
907 s->second.Print(buf, CSrvTime::eFmtHumanUSecs);
908 proxy << "Initial Sync failed - " <<
909 CNCDistributionConf::GetPeerName(s->first) << " at " << buf << endl;
910 }
911 }
912 #if USE_DETAILED_SLOT_STAT
913 ITERATE(TDetailedSyncTimes, s, s_SyncPeriodic) {
914 string peer_name(CNCDistributionConf::GetPeerNameOrEmpty(s->first));
915 if (!peer_name.empty()) {
916 const map<Uint2, CSrvTime>& per_slot = s->second;
917 for (map<Uint2, CSrvTime>::const_iterator i = per_slot.begin(); i != per_slot.end(); ++i) {
918 Uint8 agoSec = (now - i->second.AsUSec())/(kUSecsPerMSec*kMSecsPerSecond);
919 Uint8 agoUsec = (now - i->second.AsUSec())%(kUSecsPerMSec*kMSecsPerSecond);
920 i->second.Print(buf, CSrvTime::eFmtHumanUSecs);
921
922 proxy << "Periodic Sync succeeded - " <<
923 peer_name << " slot " << i->first << " " <<
924 agoSec << "." << agoUsec << "s ago" << endl;
925 }
926 }
927 }
928 #else
929 ITERATE(TSyncTimes, s, s_SyncPeriodic) {
930 string peer_name(CNCDistributionConf::GetPeerNameOrEmpty(s->first));
931 if (!peer_name.empty()) {
932 Uint8 agoSec = (now - s->second.AsUSec())/(kUSecsPerMSec*kMSecsPerSecond);
933 Uint8 agoUsec = (now - s->second.AsUSec())%(kUSecsPerMSec*kMSecsPerSecond);
934 s->second.Print(buf, CSrvTime::eFmtHumanUSecs);
935 proxy << "Periodic Sync succeeded - " <<
936 peer_name << " at " << buf << ", " <<
937 agoSec << "." << agoUsec << "s ago" << endl;
938 }
939 }
940 #endif
941 }
942 }
943
944 CSrvTime time_diff = m_EndState.state_time;
945 time_diff -= m_StartState.state_time;
946 Uint8 time_secs = time_diff.AsUSec() / kUSecsPerSecond;
947 if (time_secs == 0)
948 time_secs = 1;
949
950 proxy << "DB start - "
951 << m_StartState.db_files << " files, "
952 << g_ToSizeStr(m_StartState.db_size)
953 << " (garb - " << g_ToSizeStr(m_StartState.db_garb)
954 << ", " << g_CalcStatPct(m_StartState.db_garb, m_StartState.db_size) << "%)";
955 if (m_StartState.min_dead_time != 0) {
956 t.Sec() = m_StartState.min_dead_time;
957 t.Print(buf, CSrvTime::eFmtHumanSeconds);
958 proxy << ", dead: " << buf;
959 }
960 proxy << endl;
961 proxy << "DB end - "
962 << m_EndState.db_files << " files, "
963 << g_ToSizeStr(m_EndState.db_size) << " (garb - "
964 << g_ToSizeStr(m_EndState.db_garb) << ", "
965 << g_CalcStatPct(m_EndState.db_garb, m_EndState.db_size) << "%)";
966 if (m_EndState.min_dead_time != 0) {
967 t.Sec() = m_EndState.min_dead_time;
968 t.Print(buf, CSrvTime::eFmtHumanSeconds);
969 proxy << ", dead: " << buf;
970 }
971 proxy << endl;
972 proxy << "DB avg - "
973 << m_CntFiles.GetAverage() << " files, "
974 << g_ToSizeStr(m_DBSize.GetAverage()) << " (garb - "
975 << g_ToSizeStr(m_GarbageSize.GetAverage()) << ")" << endl;
976 proxy << "DB max - "
977 << m_CntFiles.GetMaximum() << " files, "
978 << g_ToSizeStr(m_DBSize.GetMaximum()) << " (garb - "
979 << g_ToSizeStr(m_GarbageSize.GetMaximum()) << ")" << endl;
980 proxy << "Start cache - "
981 << g_ToSmartStr(m_StartState.cnt_blobs) << " blobs, "
982 << g_ToSmartStr(m_StartState.cnt_keys) << " keys" << endl;
983 proxy << "End cache - "
984 << g_ToSmartStr(m_EndState.cnt_blobs) << " blobs, "
985 << g_ToSmartStr(m_EndState.cnt_keys) << " keys" << endl;
986 proxy << "Avg cache - "
987 << g_ToSmartStr(m_CntBlobs.GetAverage()) << " blobs, "
988 << g_ToSmartStr(m_CntKeys.GetAverage()) << " keys" << endl;
989 proxy << "Max cache - "
990 << g_ToSmartStr(m_CntBlobs.GetMaximum()) << " blobs, "
991 << g_ToSmartStr(m_CntKeys.GetMaximum()) << " keys" << endl;
992 proxy << "WB start - "
993 << g_ToSizeStr(m_StartState.wb_size) << ", releasable "
994 << g_ToSizeStr(m_StartState.wb_releasable) << ", releasing "
995 << g_ToSizeStr(m_StartState.wb_releasing) << endl;
996 proxy << "WB end - "
997 << g_ToSizeStr(m_EndState.wb_size) << ", releasable "
998 << g_ToSizeStr(m_EndState.wb_releasable) << ", releasing "
999 << g_ToSizeStr(m_EndState.wb_releasing) << endl;
1000 proxy << "WB avg - "
1001 << g_ToSizeStr(m_WBMemSize.GetAverage()) << ", releasable "
1002 << g_ToSizeStr(m_WBReleasable.GetAverage()) << ", releasing "
1003 << g_ToSizeStr(m_WBReleasing.GetAverage()) << endl;
1004 proxy << "WB max - "
1005 << g_ToSizeStr(m_WBMemSize.GetMaximum()) << ", releasable "
1006 << g_ToSizeStr(m_WBReleasable.GetMaximum()) << ", releasing "
1007 << g_ToSizeStr(m_WBReleasing.GetMaximum()) << endl;
1008 proxy << "Blob storage start - "
1009 << m_StartState.cnt_another_server_main << " requests for alien blobs, "
1010 << "blob update delay: "
1011 << (double)m_StartState.avg_tdiff_blobcopy / kUSecsPerMSec << "ms avg / "
1012 << (double)m_StartState.max_tdiff_blobcopy / kUSecsPerMSec << "ms max send, "
1013 << (double)m_StartState.avg_tdiff_blobnotify / kUSecsPerMSec << "ms avg / "
1014 << (double)m_StartState.max_tdiff_blobnotify / kUSecsPerMSec << "ms max recv "
1015 << endl;
1016 proxy << "Blob storage end - "
1017 << m_EndState.cnt_another_server_main << " requests for alien blobs, "
1018 << "blob update delay: "
1019 << (double)m_EndState.avg_tdiff_blobcopy / kUSecsPerMSec << "ms avg / "
1020 << (double)m_EndState.max_tdiff_blobcopy / kUSecsPerMSec << "ms max send, "
1021 << (double)m_EndState.avg_tdiff_blobnotify / kUSecsPerMSec << "ms avg / "
1022 << (double)m_EndState.max_tdiff_blobnotify / kUSecsPerMSec << "ms max recv "
1023 << endl;
1024 proxy << "Start mirror connections - "
1025 << g_ToSmartStr(m_StartState.peer_active_conns) << " active, "
1026 << g_ToSmartStr(m_StartState.peer_bg_conns) << " bg" << endl;
1027 proxy << "End mirror connections - "
1028 << g_ToSmartStr(m_EndState.peer_active_conns) << " active, "
1029 << g_ToSmartStr(m_EndState.peer_bg_conns) << " bg" << endl;
1030 proxy << "Avg mirror connections - "
1031 << g_ToSmartStr(m_MirrorActiveConns.GetAverage()) << " active, "
1032 << g_ToSmartStr(m_MirrorBGConns.GetAverage()) << " bg" << endl;
1033 proxy << "Max mirror connections - "
1034 << g_ToSmartStr(m_MirrorActiveConns.GetMaximum()) << " active, "
1035 << g_ToSmartStr(m_MirrorBGConns.GetMaximum()) << " bg" << endl;
1036 proxy << "Start queues - "
1037 << g_ToSmartStr(m_StartState.mirror_queue_size) << " mirror, "
1038 << g_ToSmartStr(m_StartState.sync_log_size) << " sync log" << endl;
1039 proxy << "End queues - "
1040 << g_ToSmartStr(m_EndState.mirror_queue_size) << " mirror, "
1041 << g_ToSmartStr(m_EndState.sync_log_size) << " sync log" << endl;
1042 proxy << "Avg queues - "
1043 << g_ToSmartStr(m_MirrorQSize.GetAverage()) << " mirror, "
1044 << g_ToSmartStr(m_SyncLogSize.GetAverage()) << " sync log" << endl;
1045 proxy << "Max queues - "
1046 << g_ToSmartStr(m_MirrorQSize.GetMaximum()) << " blobs, "
1047 << g_ToSmartStr(m_SyncLogSize.GetMaximum()) << " sync log" << endl;
1048 proxy << "Cmds progress - "
1049 << m_StartState.progress_cmds << " (start), "
1050 << m_EndState.progress_cmds << " (end)" << endl;
1051 proxy << "Cmds stat - "
1052 << g_ToSmartStr(m_StartedCmds) << " (start), "
1053 << g_ToSmartStr(m_CmdLens.GetCount()) << " (finish), "
1054 << g_ToSmartStr(m_ConnCmds.GetAverage()) << " (avg conn), "
1055 << g_ToSmartStr(m_ConnCmds.GetMaximum()) << " (max conn)" << endl;
1056 proxy << "Client writes - "
1057 << g_ToSizeStr(m_ClDataWrite) << ", "
1058 << g_ToSizeStr(m_ClDataWrite / time_secs) << "/s, "
1059 << g_ToSmartStr(m_ClWrBlobs) << " blobs, "
1060 << g_ToSmartStr(m_ClWrBlobs / time_secs) << " blobs/s" << endl;
1061 proxy << "Client unfinished - "
1062 << g_ToSmartStr(m_ClRbackBlobs) << " blobs of "
1063 << g_ToSizeStr(m_ClRbackSize) << endl;
1064 proxy << "Client reads - "
1065 << g_ToSizeStr(m_ClDataRead) << ", "
1066 << g_ToSizeStr(m_ClDataRead / time_secs) << "/s, "
1067 << g_ToSmartStr(m_ClRdBlobs) << " blobs, "
1068 << g_ToSmartStr(m_ClRdBlobs / time_secs) << " blobs/s" << endl;
1069 proxy << "Peer writes - "
1070 << g_ToSizeStr(m_PeerDataWrite) << ", "
1071 << g_ToSizeStr(m_PeerDataWrite / time_secs) << "/s" << endl;
1072 proxy << "Peer reads - "
1073 << g_ToSizeStr(m_PeerDataRead) << ", "
1074 << g_ToSizeStr(m_PeerDataRead / time_secs) << "/s" << endl;
1075 proxy << "Peer syncs - "
1076 << g_ToSmartStr(m_PeerSyncs) << " syncs of "
1077 << g_ToSmartStr(m_PeerSynOps) << " ops";
1078 if (m_PeerSyncs != 0)
1079 proxy << ", " << double(m_PeerSynOps) / m_PeerSyncs << " ops/sync";
1080 proxy << endl;
1081 proxy << "Disk writes - "
1082 << g_ToSizeStr(m_DiskDataWrite) << ", "
1083 << g_ToSizeStr(m_DiskDataWrite / time_secs) << "/s, "
1084 << g_ToSmartStr(m_DiskWrBlobs) << " blobs, "
1085 << g_ToSmartStr(m_DiskWrBlobs / time_secs) << " blobs/s" << endl;
1086 proxy << "Disk reads - "
1087 << g_ToSizeStr(m_DiskDataRead) << ", "
1088 << g_ToSizeStr(m_DiskDataRead / time_secs) << "/s" << endl;
1089 proxy << "Shrink check - "
1090 << g_ToSmartStr(m_CntCleanedFiles) << " files ("
1091 << g_ToSmartStr(m_CntFailedFiles) << " failed), "
1092 << g_ToSmartStr(m_CheckedRecs.GetSum()) << " recs ("
1093 << g_ToSmartStr(m_CheckedRecs.GetAverage()) << " r/file)" << endl;
1094 proxy << "Shrink moves - "
1095 << g_ToSmartStr(m_MovedRecs.GetSum()) << " recs, "
1096 << g_ToSizeStr(m_MovedSize.GetSum()) << " (per file "
1097 << g_ToSmartStr(m_MovedRecs.GetAverage()) << " recs, "
1098 << g_ToSizeStr(m_MovedSize.GetAverage()) << ")" << endl;
1099 proxy << endl;
1100
1101 m_SrvStat->PrintToSocket(proxy);
1102 x_PrintUnstructured(proxy);
1103
1104 m_StatLock.Unlock();
1105 }
1106
1107 void
DumpAllStats(void)1108 CNCStat::DumpAllStats(void)
1109 {
1110 if (!s_ThreadStat)
1111 return;
1112
1113 CNCStat* last_stat = s_CurPeriodStat[0];
1114 CNCStat::CollectThreads(last_stat, false);
1115 last_stat->PrintToLogs(kStatPeriodName[0]);
1116 for (Uint1 cur_idx = 1; cur_idx < kCntStatPeriods; ++cur_idx) {
1117 s_CurPeriodStat[cur_idx]->AddAllStats(last_stat);
1118 s_CurPeriodStat[cur_idx]->PrintToLogs(kStatPeriodName[cur_idx]);
1119 }
1120 }
1121
1122
1123 static void
s_ShiftStats(Uint1 idx)1124 s_ShiftStats(Uint1 idx)
1125 {
1126 CNCStat* prev_stat = s_PrevPeriodStat[idx];
1127 CNCStat* cur_stat = s_CurPeriodStat[idx];
1128 CNCStat* new_stat = new CNCStat();
1129 new_stat->AddReference();
1130 new_stat->TransferEndState(cur_stat);
1131
1132 s_RotateLock.Lock();
1133 s_CurPeriodStat[idx] = new_stat;
1134 s_PrevPeriodStat[idx] = cur_stat;
1135 s_RotateLock.Unlock();
1136
1137 prev_stat->RemoveReference();
1138 }
1139
1140 static void
s_CollectCurStats(void)1141 s_CollectCurStats(void)
1142 {
1143 CNCStat* last_stat = s_CurPeriodStat[0];
1144 CNCStat::CollectThreads(last_stat, true);
1145 s_ShiftStats(0);
1146 last_stat->PrintToLogs(kStatPeriodName[0]);
1147
1148 for (Uint1 cur_idx = 1; cur_idx < kCntStatPeriods; ++cur_idx) {
1149 s_CurPeriodStat[cur_idx]->AddAllStats(last_stat);
1150 }
1151 for (Uint1 cur_idx = 1; cur_idx < kCntStatPeriods; ++cur_idx) {
1152 Uint1 collected = ++s_PeriodsCollected[cur_idx];
1153 if (cur_idx == kDayPeriodIdx) {
1154 s_CheckTZChange();
1155 collected = s_PeriodsCollected[cur_idx];
1156 }
1157 if (cur_idx != kLifePeriodIdx && collected == kCollectPeriodsCnt[cur_idx]) {
1158 s_CurPeriodStat[cur_idx]->PrintToLogs(kStatPeriodName[cur_idx]);
1159 s_ShiftStats(cur_idx);
1160 s_PeriodsCollected[cur_idx] = 0;
1161 if (cur_idx == kMonthPeriodIdx)
1162 s_SetCurMonthSize();
1163 }
1164 else if (cur_idx + 1 != kMonthPeriodIdx)
1165 break;
1166 }
1167 }
1168
1169
CStatRotator(void)1170 CStatRotator::CStatRotator(void)
1171 {
1172 #if __NC_TASKS_MONITOR
1173 m_TaskName = "CStatRotator";
1174 #endif
1175 }
1176
~CStatRotator(void)1177 CStatRotator::~CStatRotator(void)
1178 {}
1179
1180 void
CalcNextRun(void)1181 CStatRotator::CalcNextRun(void)
1182 {
1183 #ifdef NCBI_OS_LINUX
1184 time_t cur_secs = CSrvTime::CurSecs();
1185 struct tm t;
1186 gmtime_r(&cur_secs, &t);
1187 RunAfter(kMinStatPeriod - t.tm_sec % kMinStatPeriod);
1188 #endif
1189 }
1190
1191 void
ExecuteSlice(TSrvThreadNum)1192 CStatRotator::ExecuteSlice(TSrvThreadNum /* thr_num */)
1193 {
1194 int cur_secs = CSrvTime::CurSecs();
1195 if (cur_secs != s_LastRotateSecs) {
1196 int cnt_iter = (cur_secs - s_LastRotateSecs) / kMinStatPeriod;
1197 if (cnt_iter == 0)
1198 cnt_iter = 1;
1199 for (int i = 0; i < cnt_iter; ++i) {
1200 if (CTaskServer::IsInShutdown())
1201 return;
1202
1203 // collect statistics from all threads
1204 // and print it into log.
1205
1206 // there are several types of stat; see kStatPeriodName above
1207
1208 s_CollectCurStats();
1209 }
1210 s_LastRotateSecs = cur_secs;
1211 }
1212 else if (CTaskServer::IsInShutdown())
1213 return;
1214 // every 5 sec
1215 CalcNextRun();
1216 }
1217
1218 END_NCBI_SCOPE
1219