| 3755 | } |
| 3756 | |
| 3757 | void* checkThread(void* arg) { |
| 3758 | #ifdef __linux__ |
| 3759 | pthread_t mainThread = *(pthread_t*)arg; |
| 3760 | free(arg); |
| 3761 | |
| 3762 | int64_t lastRunLoopIterations = net2RunLoopIterations.load(); |
| 3763 | int64_t lastRunLoopSleeps = net2RunLoopSleeps.load(); |
| 3764 | |
| 3765 | double slowTaskStart = 0; |
| 3766 | double lastSlowTaskSignal = 0; |
| 3767 | double lastSaturatedSignal = 0; |
| 3768 | double lastSlowTaskBlockedLog = 0; |
| 3769 | |
| 3770 | const double minSlowTaskLogInterval = |
| 3771 | std::max(FLOW_KNOBS->SLOWTASK_PROFILING_LOG_INTERVAL, FLOW_KNOBS->RUN_LOOP_PROFILING_INTERVAL); |
| 3772 | const double minSaturationLogInterval = |
| 3773 | std::max(FLOW_KNOBS->SATURATION_PROFILING_LOG_INTERVAL, FLOW_KNOBS->RUN_LOOP_PROFILING_INTERVAL); |
| 3774 | |
| 3775 | double slowTaskLogInterval = minSlowTaskLogInterval; |
| 3776 | double saturatedLogInterval = minSaturationLogInterval; |
| 3777 | |
| 3778 | while (true) { |
| 3779 | threadSleep(FLOW_KNOBS->RUN_LOOP_PROFILING_INTERVAL); |
| 3780 | |
| 3781 | int64_t currentRunLoopIterations = net2RunLoopIterations.load(); |
| 3782 | int64_t currentRunLoopSleeps = net2RunLoopSleeps.load(); |
| 3783 | |
| 3784 | bool slowTask = lastRunLoopIterations == currentRunLoopIterations; |
| 3785 | bool saturated = lastRunLoopSleeps == currentRunLoopSleeps; |
| 3786 | |
| 3787 | if (slowTask) { |
| 3788 | double t = timer(); |
| 3789 | bool newSlowTask = lastSlowTaskSignal == 0; |
| 3790 | |
| 3791 | if (newSlowTask) { |
| 3792 | slowTaskStart = t; |
| 3793 | } else if (t - std::max(slowTaskStart, lastSlowTaskBlockedLog) > FLOW_KNOBS->SLOWTASK_BLOCKED_INTERVAL) { |
| 3794 | lastSlowTaskBlockedLog = t; |
| 3795 | // When this gets logged, it will be with a current timestamp (using timer()). If the network thread |
| 3796 | // unblocks, it will log any slow task related events at an earlier timestamp. That means the order of |
| 3797 | // events during this sequence will not match their timestamp order. |
| 3798 | TraceEvent(SevWarnAlways, "RunLoopBlocked").detail("Duration", t - slowTaskStart); |
| 3799 | } |
| 3800 | |
| 3801 | if (newSlowTask || t - lastSlowTaskSignal >= slowTaskLogInterval) { |
| 3802 | if (lastSlowTaskSignal > 0) { |
| 3803 | slowTaskLogInterval = std::min(FLOW_KNOBS->SLOWTASK_PROFILING_MAX_LOG_INTERVAL, |
| 3804 | FLOW_KNOBS->SLOWTASK_PROFILING_LOG_BACKOFF * slowTaskLogInterval); |
| 3805 | } |
| 3806 | |
| 3807 | lastSlowTaskSignal = t; |
| 3808 | checkThreadTime.store(lastSlowTaskSignal); |
| 3809 | pthread_kill(mainThread, SIGPROF); |
| 3810 | } |
| 3811 | } else { |
| 3812 | slowTaskStart = 0; |
| 3813 | lastSlowTaskSignal = 0; |
| 3814 | lastRunLoopIterations = currentRunLoopIterations; |
nothing calls this directly
no test coverage detected