Uploaded image for project: 'OpenVZ'
  1. OpenVZ
  2. OVZ-6836

increase latency of network syscalls day by day

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Critical
    • Resolution: Fixed
    • Fix Version/s: CU-2.6.32-042stab117.X
    • Component/s: Containers::Kernel
    • Security Level: Public
    • Environment:

      Description

      >Description of problem:
      after upgrade kernel from vzkernel-2.6.32-042stab116.2.x86_64
      to any 042stab117 or 042stab120 we got an increase latency of network syscalls
      These increase are permanent day by day, from 0 usec to thousand usecs
      =====
      Process 15371 detached
      % time seconds usecs/call calls errors syscall
      ------ ----------- ----------- --------- --------- ----------------
      Fri Nov 25 10:20:02 MSK 2016 = 1196 ====
      0.00 0.000000 0 37 37 connect
      Fri Nov 25 10:25:01 MSK 2016 = 1196 ====
      0.00 0.000000 0 25 25 connect
      Fri Nov 25 10:30:01 MSK 2016 = 1196 ====
      3.04 0.000215 1 208 208 connect
      Fri Nov 25 10:35:01 MSK 2016 = 1196 ====
      4.58 0.000077 0 176 176 connect
      Fri Nov 25 10:40:01 MSK 2016 = 1196 ====
      0.83 0.000038 0 82 82 connect
      Fri Nov 25 10:45:01 MSK 2016 = 1196 ====
      5.95 0.000155 1 174 174 connect
      Fri Nov 25 10:50:01 MSK 2016 = 1196 ====
      1.93 0.000073 1 97 97 connect
      Fri Nov 25 10:55:01 MSK 2016 = 1196 ====
      27.25 0.000230 2 125 125 connect
      Fri Nov 25 11:00:01 MSK 2016 = 1196 ====
      3.49 0.000332 4 88 88 connect
      Fri Nov 25 22:20:01 MSK 2016 = 29652 ====
      99.66 0.068016 576 118 118 connect
      Fri Nov 25 22:25:01 MSK 2016 = 29652 ====
      88.84 0.024566 534 46 46 connect
      Fri Nov 25 22:30:01 MSK 2016 = 29652 ====
      99.38 0.068092 636 107 107 connect
      Fri Nov 25 22:35:01 MSK 2016 = 29652 ====
      92.95 0.027534 562 49 49 connect
      Fri Nov 25 22:40:01 MSK 2016 = 29652 ====
      90.43 0.110872 706 157 157 connect
      Fri Nov 25 22:45:01 MSK 2016 = 29652 ====
      94.70 0.037703 554 68 68 connect
      Sat Nov 26 21:35:01 MSK 2016 = 29652 ==== 9
      9.84 0.141187 1535 92 92 connect
      Sat Nov 26 21:40:01 MSK 2016 = 29652 ====
      98.73 0.344131 1516 227 227 connect
      Sat Nov 26 21:45:01 MSK 2016 = 29652 ====
      97.66 0.092836 1428 65 65 connect
      Sat Nov 26 21:50:01 MSK 2016 = 29652 ====
      98.04 0.118849 1606 74 74 connect
      Sat Nov 26 21:55:01 MSK 2016 = 29652 ====
      98.91 0.134599 1402 96 96 connect
      Sat Nov 26 22:00:01 MSK 2016 = 29652 ====
      94.08 0.062155 1381 45 45 connect

      perf top
      =====
      Samples: 329K of event 'cycles', Event count (approx.): 103104286646
      Overhead Shared Object Symbol
         1,43% [kernel] [k] dst_ops_extend_get_rcu
         0,79% [unknown] [.] 0x00007fb31cc9777f
         0,75% libc-2.5.so [.] memcpy
         0,68% [kernel] [k] copy_user_generic_string
         0,67% [unknown] [.] 0x00007fb31ccb24fb
         0,57% [unknown] [.] 0x00007fb3233a3781
         0,53% libc-2.5.so [.] memmove
         0,50% [unknown] [.] 0x00007fb3233a18a9
         0,45% [unknown] [.] 0x00007fb31ccbfd87
         0,38% [kernel] [k] page_fault
         0,35% [unknown] [.] 0x00007fb31cc969b2
         0,34% [unknown] [.] 0x00007fb31cccfa3f
         0,33% [unknown] [.] 0x00007fb3233a04a1
         0,33% libc-2.12.so [.] memcpy
         0,33% mysqld [.] 0x0000000000168b37
         0,31% [kernel] [k] ia32_sysenter_target
         0,31% [kernel] [k] clear_page_c
         0,30% [kernel] [k] fget_light
         0,29% mysqld [.] _mi_rec_unpack
         0,28% [unknown] [.] 0x00007fb31cc4ed30
         0,28% [unknown] [.] 0x00007fb3233a3760
         0,28% [unknown] [.] 0x00007fb31ccd01b0
         0,28% [unknown] [.] 0x00007fb31cc97bc1
         0,27% [unknown] [.] 0x00007fb31cabf400
         0,27% [unknown] [.] 0x00007fb31cc96b31
         0,27% [unknown] [.] 0x00007fb31cccfa0e
         0,26% [unknown] [.] 0x00007fb31cd37900
         0,26% [unknown] [.] 0x00007fb31cc97bbf
         0,26% [unknown] [.] 0x00007fb31cc96b2f
         0,25% [kernel] [k] __alloc_pages_nodemask
         0,25% [unknown] [.] 0x00007fb31cccfa3d
         0,24% [unknown] [.] 0x00007fb3233a3768
         0,24% [unknown] [.] 0x00007fb31cccfa05
      =====

      The dst_ops_extend_get_rcu consumes a lot of CPU



      >How reproducible:
      kernel from 042stab117 and some network load

      >Host OS:
      CentOS release 6.8
      >Guest OS:
      CentOS release 6.8
      >Additional info (see https://openvz.org/Reporting_OpenVZ_problem):

        Attachments

          Activity

            People

            Assignee:
            vvs Vasily Averin
            Reporter:
            atway Serg Kotelnikov
            Votes:
            0 Vote for this issue
            Watchers:
            4 Start watching this issue

              Dates

              Created:
              Updated:
              Resolved: