Uploaded image for project: 'Couchbase Server'
  1. Couchbase Server
  2. MB-45083

Slow STAT operations observed

    XMLWordPrintable

Details

    • Bug
    • Resolution: Fixed
    • Critical
    • 7.0.0
    • Cheshire-Cat
    • memcached
    • None
    • Untriaged
    • 1
    • Yes
    • KV-Engine 2021-March

    Description

      In the output from http://perf.jenkins.couchbase.com/view/Eventing/job/themis/9426/console the following slow stat operations was seen

      cbcollect_info_ns_1@172.23.96.17_20210318-214647/memcached.log:2021-03-18T13:52:05.609557-07:00 WARNING 146: Slow operation. {"cid":"127.0.0.1:47635/0","duration":"1983 ms","trace":"request=2466646701127492:1983136 execute=2466646701127492:1983136","command":"STAT","peer":"{"ip":"127.0.0.1","port":47635}","bucket":"bucket-1","packet":{"bodylen":0,"cas":0,"datatype":"raw","extlen":0,"key":"<ud></ud>","keylen":0,"magic":"ClientRequest","opaque":0,"opcode":"STAT","vbucket":0}}
      cbcollect_info_ns_1@172.23.96.17_20210318-214647/memcached.log:2021-03-18T13:54:16.555175-07:00 WARNING 284: Slow operation. {"cid":"127.0.0.1:47200/0","duration":"1123 ms","trace":"request=2466778509361025:1122805 execute=2466778509361025:1122805","command":"STAT","peer":"{"ip":"127.0.0.1","port":47200}","bucket":"eventing-bucket-1","packet":{"bodylen":0,"cas":0,"datatype":"raw","extlen":0,"key":"<ud></ud>","keylen":0,"magic":"ClientRequest","opaque":0,"opcode":"STAT","vbucket":0}}
      

      On that node:

      The following data is collected for "STAT"
      [  0.00 -   5.00]us (0.0000%)	   19| 
      [  5.00 -  55.00]us (10.0000%)	 2854| ##################################
      [ 55.00 -  63.00]us (20.0000%)	 2966| ###################################
      [ 63.00 -  71.00]us (30.0000%)	 3667| ############################################
      [ 71.00 -  75.00]us (40.0000%)	 1335| ################
      [ 75.00 -  87.00]us (50.0000%)	 2545| ##############################
      [ 87.00 -  95.00]us (55.0000%)	 1402| ################
      [ 95.00 - 103.00]us (60.0000%)	 1624| ###################
      [103.00 - 111.00]us (65.0000%)	 1236| ##############
      [111.00 - 119.00]us (70.0000%)	 1155| #############
      [119.00 - 159.00]us (75.0000%)	 1224| ##############
      [159.00 - 207.00]us (77.5000%)	  726| ########
      [207.00 - 247.00]us (80.0000%)	  572| ######
      [247.00 - 383.00]us (82.5000%)	  764| #########
      [383.00 - 511.00]us (85.0000%)	  529| ######
      [  0.51 -   1.22]ms (87.5000%)	  929| ###########
      [  1.22 -   1.28]ms (88.7500%)	  290| ###
      [  1.28 -   1.34]ms (90.0000%)	  213| ##
      [  1.34 -   1.47]ms (91.2500%)	  253| ###
      [  1.47 -   1.86]ms (92.5000%)	  403| ####
      [  1.86 -   2.05]ms (93.7500%)	  339| ####
      [  2.05 -   2.17]ms (94.3750%)	  222| ##
      [  2.17 -   2.30]ms (95.0000%)	  173| ##
      [  2.30 -   2.43]ms (95.6250%)	  341| ####
      [  2.43 -   2.43]ms (96.2500%)	    0| 
      [  2.43 -   2.43]ms (96.8750%)	    0| 
      [  2.43 -   2.56]ms (97.1875%)	  262| ###
      [  2.56 -   2.56]ms (97.5000%)	    0| 
      [  2.56 -   2.56]ms (97.8125%)	    0| 
      [  2.56 -   2.69]ms (98.1250%)	   74| 
      [  2.69 -   2.82]ms (98.4375%)	   87| #
      [  2.82 -   2.94]ms (98.5938%)	  118| #
      [  2.94 -   2.94]ms (98.7500%)	    0| 
      [  2.94 -   2.94]ms (98.9062%)	    0| 
      [  2.94 -   3.07]ms (99.0625%)	  100| #
      [  3.07 -   3.07]ms (99.2188%)	    0| 
      [  3.07 -   3.07]ms (99.2969%)	    0| 
      [  3.07 -   3.20]ms (99.3750%)	   56| 
      [  3.20 -   3.20]ms (99.4531%)	    0| 
      [  3.20 -   3.33]ms (99.5312%)	   10| 
      [  3.33 -   3.97]ms (99.6094%)	   21| 
      [  3.97 -   4.35]ms (99.6484%)	   10| 
      [  4.35 -   5.89]ms (99.6875%)	    7| 
      [  5.89 -  13.82]ms (99.7266%)	   11| 
      [ 13.82 -  25.60]ms (99.7656%)	   10| 
      [ 25.60 -  43.01]ms (99.8047%)	   11| 
      [ 43.01 -  53.25]ms (99.8242%)	    5| 
      [ 53.25 -  59.39]ms (99.8438%)	    6| 
      [ 59.39 -  65.54]ms (99.8633%)	    4| 
      [ 65.54 -  73.73]ms (99.8828%)	    6| 
      [ 73.73 -  81.92]ms (99.9023%)	    6| 
      [ 81.92 -  86.01]ms (99.9121%)	    3| 
      [ 86.01 -  90.11]ms (99.9219%)	    1| 
      [ 90.11 -  98.30]ms (99.9316%)	    2| 
      [ 98.30 - 106.50]ms (99.9414%)	    5| 
      [106.50 - 110.59]ms (99.9512%)	    1| 
      [110.59 - 114.69]ms (99.9561%)	    2| 
      [114.69 - 114.69]ms (99.9609%)	    0| 
      [114.69 - 122.88]ms (99.9658%)	    2| 
      [122.88 - 126.97]ms (99.9707%)	    1| 
      [126.97 - 139.26]ms (99.9756%)	    2| 
      [139.26 - 139.26]ms (99.9780%)	    0| 
      [139.26 - 139.26]ms (99.9805%)	    0| 
      [139.26 - 147.46]ms (99.9829%)	    1| 
      [147.46 - 196.61]ms (99.9854%)	    1| 
      [196.61 - 196.61]ms (99.9878%)	    0| 
      [196.61 - 786.43]ms (99.9890%)	    1| 
      [786.43 - 786.43]ms (99.9902%)	    0| 
      [786.43 - 786.43]ms (99.9915%)	    0| 
      [  0.79 -   1.18]s (99.9927%)	    1| 
      [  1.18 -   1.18]s (99.9939%)	    0| 
      [  1.18 -   1.18]s (99.9945%)	    0| 
      [  1.18 -   1.18]s (99.9951%)	    0| 
      [  1.18 -   1.18]s (99.9957%)	    0| 
      [  1.18 -   2.03]s (99.9963%)	    1| 
      [  2.03 -   2.03]s (100.0000%)	    0| 
      Total: 26609 operations
      

      We should figure out why we see those really really slow stat ops

      Attachments

        No reviews matched the request. Check your Options in the drop-down menu of this sections header.

        Activity

          People

            trond Trond Norbye
            trond Trond Norbye
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Gerrit Reviews

                There are no open Gerrit changes

                PagerDuty