Измерение DirectByteBuffer с помощью асинхронного профилировщика и перфорации - PullRequest
0 голосов
/ 20 сентября 2018

Я играю с async-profiler и perf и решил измерить активность ядра для DirectByteBuffer дискового ввода-вывода.Вот код (написанный на Scala, но его Java-версия должна быть очевидной):

val path = Paths.get("/tmp/test")

val buffer = ByteBuffer.allocateDirect(4096 * 4096)

def main(args: Array[String]): Unit = {
  var fullReadsCount = 0
  while (true) {
    var bytesRead = 0
    var ch: SeekableByteChannel = null
    try {
      ch = Files.newByteChannel(path)
      while (bytesRead >= 0) {
        bytesRead = ch.read(buffer)
        buffer.clear()
      }
    } finally {
      if (ch != null)
        ch.close()
    }
    fullReadsCount += 1
    if(fullReadsCount % 100 == 0) println(fullReadsCount)
  }
}

Я запускал этот код несколько раз, выполнил и perf и async-profiler и заметил следующий результат:

  1. асинхронный профилировщик

    $~/profiler.sh -i 28169 -d 30 <pid>
     //.... stack traces ommited
         ns  percent  samples  top
    
    264788732   61.02%     9317  copy_user_enhanced_fast_string_[k]
     41510919    9.57%     1467  generic_file_read_iter_[k]
      9333863    2.15%      331  find_get_entry_[k]
      4181131    0.96%      148  __radix_tree_lookup_[k]
      4057194    0.94%      143  copy_page_to_iter_[k]
      1860485    0.43%       63  __d_lookup_rcu_[k]
      1610407    0.37%       50  _raw_spin_unlock_irqrestore_[k]
    
  2. perf sudo perf record -F 31499 -g -p <pid> -- sleep 30

enter image description here

В среднем среди всех запусков, которые я сделал, я заметил, что copy_user_enhanced_fast_string процент отличается в perf и async-profiler 61.02% против 77.65%

ВОПРОС: Почему процентное соотношение для copy_user_enhanced_fast_string отличается от perf и async-profiler?Я пытался обеспечить равные условия (частота и период выборки, и я не запускал оба профилировщика одновременно. 31499 Гц ≈ 28169 нано).

Или моя интерпретация результата неверна?

1 Ответ

0 голосов
/ 21 сентября 2018

Выбранный интервал профилирования (28 мкс) слишком короткий.
Проверка dmesg - возможно, есть предупреждения ядра, такие как

perf interrupt took too long (18047 > 18000), lowering kernel.perf_event_max_sample_rate to 25000

async-profiler отличается от perf в механизмеобработка событий PMU.perf просто собирает сэмплы в кольцевом буфере, в то время как async-profiler посылает сигнал процессу, чтобы вызвать специфичный для приложения обратный вызов.Обычно нет видимой разницы для пользователя, но когда частота профилирования слишком высока, сигналы могут вносить дополнительный шум и влиять на планирование процесса.

Я предлагаю увеличить интервал профилирования по крайней мере до 100 мкс (10000 Гц).Это должно сделать измерения более надежными.

...