Низкая производительность ttcp
Следующая ситуация - это продолжение примера из совета 36. Помните, что при размере буфера равном MSS соединения, время передачи 16 Мб возросло с 1,3 с до почти 41 мин.
На рис. 4.18 приведена репрезентативная выборка из результатов прогона ktrace для этого примера.
12512 ttcp 0.000023 CALL write(0x3,0x8050000, 0x2000)
12512 ttcp 1.199605 GIO fd 3 wrote 8192 bytes
“”
12512 ttcp 0.000442 RET write 8192/0x2000
12512 ttcp 0.000022 CALL write(0x3,0x8050000 , 0x2000)
12512 ttcp 1.199574 GIO fd 3 wrote 8192 bytes
“”
12512 ttcp 0.000442 RET write 8192/0x2000
12512 ttcp 0.000023 CALL write(0x3,0x8050000 , 0x2000)
12512 ttcp 1.199514 GIO fd 3 wrote 8192 bytes
“”
12512 ttcp 0.000432 RET write 8192/0x2000
Рис. 4.18. Выборка из результатов проверки ttcp -tsvb 1448 bsd под управлением ktrace
Вызвана kdump со следующими опциями:
kdump -R -m -l
для печати интервалов времени между вызовами и запрета вывода 8 Кб данных, ассоциированных с каждым системным вызовом.
Время каждой операции записи колеблется около значения 1,2 с. На рис. 4.19 для сравнения приведены результаты эталонного теста. На этот раз разброс значений несколько больше, но среднее время записи составляет менее 0,5 мс.
Большее время в записях типа GIO на рис. 4.18 по сравнению с временем на рис. 4.19 наводит на мысль, что операции записи блокировались в ядре (совет 36). Тогда становится понятна истинная причина столь резкого увеличения времени передачи.
12601 ttcp 0.000033 CALL write(0x3,0x8050000, 0x2000) 12601 ttcp 0.000279 GIO fd 3 wrote 8192 bytes
“”
12601 ttcp 0.000360 RET write 8192/0x2000
12601 ttcp 0.000033 CALL write(0x3,0x8050000, 0x2000)
12601 ttcp 0.000527 GIO fd 3 wrote 8192 bytes
“”
12601 ttcp 0.000499 RET write 8192/0x2000
12601 ttcp 0.000032 CALL write(0x3,0x8050000, 0x2000)
12601 ttcp 0.000282 GIO fd 3 wrote 8192 bytes
“”
12601 ttcp 0.000403 RET write 8192/0x2000
Рис. 4.19. Репрезентативная выборка из результатов проверки ttcp –tsvbsd под управлением ktrace