13

I was debugging high System CPU usage (Not user CPU usage) on of our storm supervisors (Wheezy machine). Here are the observations

Output of perf for the relevant process: 

Events: 10K cpu-clock
16.40%  java  [kernel.kallsyms]   [k] system_call_after_swapgs
13.95%  java  [kernel.kallsyms]   [k] pvclock_clocksource_read
12.76%  java  [kernel.kallsyms]   [k] do_gettimeofday
12.61%  java  [vdso]              [.] 0x7ffe0fea898f
 9.02%  java  perf-17609.map      [.] 0x7fcabb8b85dc
 7.16%  java  [kernel.kallsyms]   [k] copy_user_enhanced_fast_string
 4.97%  java  [kernel.kallsyms]   [k] native_read_tsc
 2.88%  java  [kernel.kallsyms]   [k] sys_gettimeofday
 2.82%  java  libjvm.so           [.] os::javaTimeMillis()
 2.39%  java  [kernel.kallsyms]   [k] arch_local_irq_restore

Caught this in strace of a thread of the relevant process

% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
100.00    0.000247           0     64038           gettimeofday
  0.00    0.000000           0         1           rt_sigreturn
  0.00    0.000000           0         1           futex
------ ----------- ----------- --------- --------- ----------------
100.00    0.000247                 64040           total

Finally figured out that the thread was running in while(true) and one of the calls inside was System.currentTimeMillis(). I disabled the same and the system CPU % went down from 50% to 3%. So clearly that was the issue. What I fail to understand is, in the presence of vDSO these kernel calls should only happen in the user's address space. But as is clear from perf report, kernel calls are indeed taking place in the kernel space. Any pointers on this? Kernel version: 3.2.0-4-amd64 Debian 3.2.86-1 x86_64 GNU/Linux
clock type: kvm

Adding code of the problematic thread. 

@RequiredArgsConstructor
public class TestThread implements Runnable {
    private final Queue<String> queue;
    private final Publisher publisher;
    private final int maxBatchSize;

    private long lastPushTime;
    @Override
    public void run() {
        lastPushTime = System.currentTimeMillis();
        List<String> events = new ArrayList<>();
        while (true) {
            try {
                String message = queue.poll();
                long lastPollTime = System.currentTimeMillis();
                if (message != null) {
                    events.add(message);
                    pushEvents(events, false);
                }

                // if event threshold hasn't reached the size, but it's been there for over 10seconds, push it.
                if ((lastPollTime - lastPushTime > 10000) && (events.size() > 0)) {
                    pushEvents(events, true);
                }
            } catch (Exception e) {
                // Log and do something
            }
        }
    }

    private void pushEvents(List<String> events, boolean forcePush) {
        if (events.size() >= maxBatchSize || forcePush) {
            pushToHTTPEndPoint(events);
            events.clear();
            lastPushTime = System.currentTimeMillis();
        }
    }

    private void pushToHTTPEndPoint(List<String> events) {
        publisher.publish(events);
    }
}
4

4 回答 4

4

我不明白的是，在存在 vDSO 的情况下，这些内核调用应该只发生在用户的地址空间中。但是从 perf 报告中可以清楚地看出，内核调用确实发生在内核空间中。对此有任何指示吗？

可以在虚拟系统上禁用 vDSO。KVM 使用 PVClock（您可以在这篇不错的文章中了解更多信息），它取决于内核版本。例如，我们可以在这里看到 VCLOCK_MODE 永远不会被覆盖。另一方面，这里也更改了 vDSO 的 vclock_mode - 和 vclock_mode指示器。

此支持在此提交中引入，并在 3.8 版本的 Linux 内核中发布。

一般来说，在我的实践中，如果你长时间调用“while(true)”里面的东西，你总是会看到一个很大的 CPU 消耗。

当然，Blocking Queue 在大多数情况下就足够了，但如果您需要良好的延迟和性能，您也可以使用 spin，无需线程阻塞，但您应该限制 spin 周期并进行基准测试来衡量这种优化的影响。元代码可能类似于：

int spin = 100;
while(spin-- > 0) {
    // try to get result
}
// still no result -> execute blocking code
于 2018-01-06T09:01:32.750 回答
4

循环内没有其他值得注意的地方，所以你正在旋转System.currentTimeMillis()

vDSO 将有助于提高性能System.currentTimeMillis()，但它真的将 CPU 的分类从“系统”更改为“用户”吗？我不知道，对不起。

该线程将消耗 100% CPU，是否将其归类为“系统”或“用户”有很大的不同？

例如，您应该重写此代码以使用非旋转等待BlockingQueue.poll(timeout)

您在这里的实际问题是什么？

我不明白的是，在存在 vDSO 的情况下，这些内核调用应该只发生在用户的地址空间中。但是从 perf 报告中可以清楚地看出，内核调用确实发生在内核空间中。对此有任何指示吗？

为什么在这个自旋锁中花费的 CPU 时间如何分类很重要？

根据用户 CPU 时间与系统 CPU 时间？“系统 CPU 时间”为：

系统 CPU 时间：处理器处理与该特定程序相关的操作系统功能的时间。

根据该定义，旋转所花费的时间System.currentTimeMillis()将计为系统时间，即使由于 vDSO 而不需要用户到内核模式切换。

于 2018-01-02T14:16:23.437 回答
3

所以我在这里发现了这个问题。为了提供更多背景信息，问题更多的是关于 vDSO 进行系统调用的事实（如果原始帖子具有误导性，请致歉！）。此内核版本 (kvmclock) 的时钟源不支持虚拟系统调用，因此发生了真正的系统调用。它在此提交中引入https://github.com/torvalds/linux/commit/3dc4f7cfb7441e5e0fed3a02fc81cdaabd28300a#diff-5a34e1e52f50e00cef4b0d0ff3fef8f7（感谢 egorlitvinenko 指出这一点。

另外，我确实知道 while(true) 中的任何内容都会消耗 CPU。由于这是在 apachestorm 上下文中，调用本质上是在进行 HTTP 调用之前对事件进行批处理，因此可以通过使用 apachestorm 的 tick tuples 支持以更好的方式完成此操作。

于 2018-01-09T11:49:35.047 回答
2

通过阅读您的代码，没有控制代码来阻止 while 循环，除了publisher.publish(events)and queue.poll()，这意味着该线程正忙于 while 循环，永远不要休息。

在我看来，你需要限制调用。System.currentTimeMillis()一个不错的选择是queue.poll()阻塞，一些伪代码：

while (!stopWork) {
    try {
        // wait for messages with 10 seconds timeout,if no message or timeout return empty list
        // this is easy to impl with BlockingQueue
        List<String> events = queue.poll(10,TimeUnit.SECOND);
        if (events.isEmpty()) {
            continue;
        }
        new java.util.Timer().schedule( 
            new java.util.TimerTask() {
                @Override
                public void run() {
                    pushEvents(events, true);
                }
            }, 1000*10 );
    } catch (Exception e) {
        // Log and do something
    }
}
于 2018-01-04T05:14:39.613 回答