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

Closing DCP connection due to "getMessageSize should not be called" exception

    XMLWordPrintable

Details

    Description

      During the kv-engine-cheshire-cat-jepsen-nightly-512 job we observed the following error messages de to an exception being thrown regarding getMessageSize() being called.

      04:39:18 Error log messages where found in memached.log's
      04:39:18 ./20210527T155653.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-225938/memcached.log:2021-05-27T15:58:42.097906-07:00 ERROR 61: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":54845} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0027</ud>","keylen":11,"magic":"ClientRequest","opaque":53,"opcode":"DCP_ABORT","vbucket":477},"refcount":1}]
      04:39:18 ./20210527T155653.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-225938/memcached.log:2021-05-27T15:58:42.098406-07:00 ERROR 63: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":40253} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0015</ud>","keylen":11,"magic":"ClientRequest","opaque":86,"opcode":"DCP_ABORT","vbucket":254},"refcount":1}]
      04:39:18 ./20210527T155653.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-225938/memcached.log:2021-05-27T15:58:54.033472-07:00 ERROR 61: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":55435} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0021</ud>","keylen":11,"magic":"ClientRequest","opaque":107,"opcode":"DCP_ABORT","vbucket":190},"refcount":1}]
      04:39:18 ./20210527T155653.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-225938/memcached.log:2021-05-27T15:58:56.681055-07:00 ERROR 63: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":56897} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0013</ud>","keylen":11,"magic":"ClientRequest","opaque":73,"opcode":"DCP_ABORT","vbucket":413},"refcount":1}]
      04:39:18 ./20210527T155653.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-225938/memcached.log:2021-05-27T15:58:57.885582-07:00 ERROR 61: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":33005} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0021</ud>","keylen":11,"magic":"ClientRequest","opaque":107,"opcode":"DCP_ABORT","vbucket":190},"refcount":1}]
      04:39:18 ./20210527T155653.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-225938/memcached.log:2021-05-27T15:59:03.961412-07:00 ERROR 63: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":46313} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0013</ud>","keylen":11,"magic":"ClientRequest","opaque":73,"opcode":"DCP_ABORT","vbucket":413},"refcount":1}]
      04:39:18 ./20210527T155653.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-225938/memcached.log:2021-05-27T15:59:07.926468-07:00 ERROR 67: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":34751} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0022</ud>","keylen":11,"magic":"ClientRequest","opaque":99,"opcode":"DCP_ABORT","vbucket":439},"refcount":1}]
      04:39:18 ./20210527T155653.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-225938/memcached.log:2021-05-27T15:59:12.671179-07:00 ERROR 65: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":54179} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0013</ud>","keylen":11,"magic":"ClientRequest","opaque":73,"opcode":"DCP_ABORT","vbucket":413},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.227/cbcollect_info_ns_1@172.23.107.227_20210527-235728/memcached.log:2021-05-27T16:56:47.476226-07:00 ERROR 56: Exception occurred during packet execution. Closing connection: CommitSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":53817} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0015</ud>","keylen":11,"magic":"ClientRequest","opaque":172,"opcode":"DCP_COMMIT","vbucket":254},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.227/cbcollect_info_ns_1@172.23.107.227_20210527-235728/memcached.log:2021-05-27T16:56:53.199197-07:00 ERROR 62: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":34897} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0020</ud>","keylen":11,"magic":"ClientRequest","opaque":102,"opcode":"DCP_ABORT","vbucket":953},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:56:38.298996-07:00 ERROR 64: Exception occurred during packet execution. Closing connection: CommitSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":37719} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0026</ud>","keylen":11,"magic":"ClientRequest","opaque":135,"opcode":"DCP_COMMIT","vbucket":730},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:56:38.574657-07:00 ERROR 44: Exception occurred during packet execution. Closing connection: CommitSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":54107} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0000</ud>","keylen":11,"magic":"ClientRequest","opaque":61,"opcode":"DCP_COMMIT","vbucket":399},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:56:38.575886-07:00 ERROR 60: Exception occurred during packet execution. Closing connection: CommitSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":41891} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0015</ud>","keylen":11,"magic":"ClientRequest","opaque":172,"opcode":"DCP_COMMIT","vbucket":254},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:56:45.126826-07:00 ERROR 64: Exception occurred during packet execution. Closing connection: CommitSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":42417} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0027</ud>","keylen":11,"magic":"ClientRequest","opaque":139,"opcode":"DCP_COMMIT","vbucket":477},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:56:45.263388-07:00 ERROR 60: Exception occurred during packet execution. Closing connection: CommitSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":60477} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0006</ud>","keylen":11,"magic":"ClientRequest","opaque":154,"opcode":"DCP_COMMIT","vbucket":236},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:56:47.572941-07:00 ERROR 64: Exception occurred during packet execution. Closing connection: CommitSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":46177} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0006</ud>","keylen":11,"magic":"ClientRequest","opaque":154,"opcode":"DCP_COMMIT","vbucket":236},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:56:48.479587-07:00 ERROR 69: Exception occurred during packet execution. Closing connection: CommitSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":36977} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0027</ud>","keylen":11,"magic":"ClientRequest","opaque":139,"opcode":"DCP_COMMIT","vbucket":477},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:56:52.722275-07:00 ERROR 64: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":56869} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0003</ud>","keylen":11,"magic":"ClientRequest","opaque":52,"opcode":"DCP_ABORT","vbucket":134},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:56:57.464854-07:00 ERROR 64: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":54569} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0021</ud>","keylen":11,"magic":"ClientRequest","opaque":108,"opcode":"DCP_ABORT","vbucket":190},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:56:58.041693-07:00 ERROR 65: Exception occurred during packet execution. Closing connection: CommitSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":40059} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0027</ud>","keylen":11,"magic":"ClientRequest","opaque":139,"opcode":"DCP_COMMIT","vbucket":477},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:56:58.396226-07:00 ERROR 76: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":54339} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0018</ud>","keylen":11,"magic":"ClientRequest","opaque":40,"opcode":"DCP_ABORT","vbucket":591},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:57:02.657272-07:00 ERROR 58: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":49517} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0009</ud>","keylen":11,"magic":"ClientRequest","opaque":43,"opcode":"DCP_ABORT","vbucket":83},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:57:03.014032-07:00 ERROR 59: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":44935} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0019</ud>","keylen":11,"magic":"ClientRequest","opaque":38,"opcode":"DCP_ABORT","vbucket":328},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:57:07.888624-07:00 ERROR 59: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":58685} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0006</ud>","keylen":11,"magic":"ClientRequest","opaque":154,"opcode":"DCP_ABORT","vbucket":236},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.107.228/cbcollect_info_ns_1@172.23.107.228_20210527-235729/memcached.log:2021-05-27T16:57:08.177538-07:00 ERROR 60: Exception occurred during packet execution. Closing connection: CommitSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":59537} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0027</ud>","keylen":11,"magic":"ClientRequest","opaque":139,"opcode":"DCP_COMMIT","vbucket":477},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.106.61/cbcollect_info_ns_1@172.23.106.61_20210527-235727/memcached.log:2021-05-27T16:56:51.934257-07:00 ERROR 71: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":52689} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0007</ud>","keylen":11,"magic":"ClientRequest","opaque":153,"opcode":"DCP_ABORT","vbucket":1003},"refcount":1}]
      04:39:18 ./20210527T165516.000-0700/172.23.106.61/cbcollect_info_ns_1@172.23.106.61_20210527-235727/memcached.log:2021-05-27T16:56:51.934257-07:00 ERROR 70: Exception occurred during packet execution. Closing connection: AbortSyncWriteConsumer::getMessageSize should not be called. Cookies: [{"aiostat":"success","connection":"[ {\"ip\":\"127.0.0.1\",\"port\":42429} - {\"ip\":\"127.0.0.1\",\"port\":11209} (System, <ud>@ns_server</ud>) ]","engine_storage":"0x0000000000000000","ewouldblock":false,"packet":{"bodylen":27,"cas":0,"datatype":"raw","extlen":16,"key":"<ud>.jepsen0029</ud>","keylen":11,"magic":"ClientRequest","opaque":60,"opcode":"DCP_ABORT","vbucket":613},"refcount":1}]
      

      Seems to only affect DCP_ABORT and DCP_COMMIT.

      Attachments

        Issue Links

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

          Activity

            People

              owend Daniel Owen
              richard.demellow Richard deMellow
              Votes:
              0 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                PagerDuty