почему copy_to_user тратит несколько сотен миллисекунд?

У меня есть некоторые Linux-серверы, на которых запущен сервер трафика Apache, и обнаружил, что примерно 1/20 запросов занимает несколько миллисекунд, что намного дольше, чем ожидалось (должно быть 1-2 мс).

После отслеживания systemtap я обнаружил, что время тратится на вызов copy_to_user () ядра Linux. (Accept-> inet_csk_accept-> move_addr_to_user-> copy_to_user)

Загрузка сервера достаточно низкая (<100qps) и copy_to_user () просто копируют 16-байтовые данные (struct sockaddr), но затрачивают сотни миллисекунд.

Поскольку я совсем не знаком с системной тапой и техникой трассировки ядра, я не могу исследовать дальнейшую причину. Я проверил использование процессора, использование подкачки

Спасибо за любой совет.

Оборудование:

  • процессор: Intel (R) Xeon (R) CPU E5-2640 v3 @ 2.60GHz
  • память: 64G
  • диск: 11 * 6T HDD

Программного обеспечения:

  • centos6 2.6.32-696.el6.x86_64 # 1 SMP Вт 21 марта 19:29:05 UTC 2017 x86_64 x86_64 x86_64 GNU / Linux
  • apache trafficserver 5.3.2 настроить оперативную память 10G
  • nginx 1.10.2, запрос прокси к серверу трафика

    // systemtap
    probe kernel.function("move_addr_to_user")
    {
    ts["move_addr_to_user", pid()] = gettimeofday_ms()
    }
    
    probe kernel.function("move_addr_to_user").return
    {
    printf("[%d]move_addr_to_user done:%d %s %d\n", gettimeofday_ms(), pid(), execname(), gettimeofday_ms()-ts["move_addr_to_user", pid()])
    }
    
    probe kernel.function("copy_to_user")
    {
    ts["copy_to_user", pid()] = gettimeofday_ms()
    }
    
    probe kernel.function("copy_to_user").return
    {
    printf("[%d]copy_to_user done:%d %s %d %d\n", gettimeofday_ms(), pid(), execname(), gettimeofday_ms()-ts["copy_to_user", pid()],
    gettimeofday_ms()-ts["__copy_to_user", pid()])
    }
    
    // output:
    [1495630190767] 16 16 move_addr_to_user done:24145 [ACCEPT 0:8080] 0
    [1495630191164]copy_to_user done:24145 [ACCEPT 0:8080] 0
    [1495630191164] 16 16 move_addr_to_user done:24145 [ACCEPT 0:8080] 0
    [1495630192172]copy_to_user done:24145 [ACCEPT 0:8080] 861
    [1495630192172] 16 16 move_addr_to_user done:24145 [ACCEPT 0:8080] 861
    [1495630192173]copy_to_user done:24145 [ACCEPT 0:8080] 0
    [1495630192173] 16 16 move_addr_to_user done:24145 [ACCEPT 0:8080] 0
    [1495630192173]copy_to_user done:24145 [ACCEPT 0:8080] 0
    [1495630192173] 16 16 move_addr_to_user done:24145 [ACCEPT 0:8080] 0
    [1495630192173]copy_to_user done:24145 [ACCEPT 0:8080] 0free -g
    total       used       free     shared    buffers     cached
    Mem:            62         55          6          0          0         32
    -/+ buffers/cache:         23         39
    Swap:           15          0         15
    
    top - 20:57:39 up 24 days, 19:26,  2 users,  load average: 7.70, 9.43, 9.62
    Tasks: 643 total,   1 running, 642 sleeping,   0 stopped,   0 zombie
    Cpu(s):  0.1%us,  1.0%sy,  0.0%ni, 97.5%id,  1.1%wa,  0.0%hi,  0.3%si,  0.0%st
    Mem:  65560992k total, 58525192k used,  7035800k free,   365084k buffers
    Swap: 16777212k total,        0k used, 16777212k free, 33957572k cached
    PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
    24145 traffics  20   0 21.7g  12g 6212 S 24.7 19.3 212:42.85 [ET_NET 0]
    22173 root      20   0  677m 325m 1180 S  3.6  0.5   0:41.10 nginx
    22161 root      20   0  677m 325m 1184 S  2.6  0.5   0:47.50 nginx
    22168 root      20   0  677m 326m 2076 S  2.6  0.5   0:28.31 nginx
    22150 root      20   0  677m 325m 1208 S  1.6  0.5   0:42.75 nginx
    22165 root      20   0  677m 325m 1200 S  1.6  0.5   0:31.77 nginx
    

Обновить:

@mployee месяца, спасибо за совет, после добавления проверки на __do_page_fault я обнаружил, что время было потрачено на __do_page_fault -> down_read (&мм-> mmap_sem);

    [1495677639202]copy_to_user done:24145 [ACCEPT 0:8080] 1
[1495677639202] 16 16 move_addr_to_user done:24145 [ACCEPT 0:8080] 1
[1495677639314]copy_to_user done:24145 [ACCEPT 0:8080] 0
[1495677639314] 16 16 move_addr_to_user done:24145 [ACCEPT 0:8080] 0
[1495677641329]do page fault done:24145 [ACCEPT 0:8080] 622
[1495677641329]copy_to_user done:24145 [ACCEPT 0:8080] 622
[1495677641329] 16 16 move_addr_to_user done:24145 [ACCEPT 0:8080] 622

@Ricardo Biehl Pasquali, спасибо за ваш совет. Apache Trafficserver чтение / запись на жесткий диск в отдельных потоках. у Trafficserver есть 1 поток для принятия соединений, 88 (8 потоков на жесткий диск) для блокировки чтения / записи (содержимое кэша), но я не понимаю, почему блокировка чтения / записи в других потоках может привести к высокой задержке __do_page_fault () ,

    Device:         rrqm/s   wrqm/s     r/s     w/s   rsec/s   wsec/s avgrq-sz avgqu-sz   await r_await w_await  svctm  %util
sda               0.00    16.00    0.00    4.00     0.00   160.00    40.00     0.05   13.50    0.00   13.50   7.75   3.10
sdi               0.00     0.00    0.00    0.00     0.00     0.00      0.00     0.00    0.00    0.00    0.00   0.00   0.00
sde               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
sdd               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
sdj               0.00     0.00    6.00    0.00  4326.00     0.00   721.00     0.06   10.50   10.50    0.00   6.83   4.10
sdc               0.00     0.00    2.00    0.00  1472.00     0.00   736.00     0.04   18.50   18.50    0.00   9.50   1.90
sdh               0.00     0.00    0.00    0.00     0.00     0.00     0.00     0.00    0.00    0.00    0.00   0.00   0.00
sdg               0.00     0.00   14.00    0.00 10464.00     0.00   747.43     0.04    2.71    2.71    0.00   1.79   2.50

Обновить:

Задача решена!
Основной причиной является периодический вызов systemserver для вызова файла резервной копии в древнем плагине, который мы написали.

5

Решение

Ну, разумное объяснение состоит в том, что вы ошибаетесь на странице. Одной из возможных причин может быть то, что сервер разветвляется / завершает работу в зависимости от того, как изменяется нагрузка, и новый дочерний элемент должен давать сбой странице, но в качестве незначительной ошибки это не займет много времени, если не будет недостатка памяти.

Еще один — это нехватка памяти, и вы на самом деле меняете местами.

В любом случае, учитывая, что вы зашли так далеко, я не понимаю, в чём проблема. Вы хотите поставить зонд на __do_page_fault и продолжить оттуда.

3

Другие решения

Других решений пока нет …

А ты уже прошел курс программирования? Супер скидка!
Прокачать скилл $$$
×