Uploaded image for project: 'Couchbase Java Client'
  1. Couchbase Java Client
  2. JCBC-263

memcached connection fails with "Attempting to overwrite channel"

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Incomplete
    • Affects Version/s: 1.1.2
    • Fix Version/s: .backlog1.x
    • Component/s: Core
    • Security Level: Public
    • Labels:
      None
    • Environment:
      This is a "run of the mill" memcached instance. I have not particularly been able to reproduce it though - nevertheless I am placing it in here so that it may be noted.

      Server version is 2.0.0

      Description

      In this case, multiple CouchbaseClient objects are being connected. At the 14th instance, this is printed to the screen and the application hangs.

      [SDKD(WARNING) 5.49 cbsdk.sdkd.remote remote.py:266] WARNING: URIs: http://10.2.1.102:8091/pools?#
      [SDKD(WARNING) 5.51 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM com.couchbase.sdkd.cbclient.Handle makeViewTimeout
      [SDKD(WARNING) 5.51 cbsdk.sdkd.remote remote.py:266] WARNING: JCBC-168: Manually setting view timeout to 75000
      [SDKD(WARNING) 5.51 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM net.spy.memcached.MemcachedConnection createConnections
      [SDKD(WARNING) 5.51 cbsdk.sdkd.remote remote.py:266] INFO: Added

      {QA sa=/10.2.1.102:11210, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null, toWrite=0, interested=0}

      to connect queue
      [SDKD(WARNING) 5.53 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM net.spy.memcached.MemcachedConnection createConnections
      [SDKD(WARNING) 5.53 cbsdk.sdkd.remote remote.py:266] INFO: Added

      {QA sa=/10.2.1.101:11210, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null, toWrite=0, interested=0}

      to connect queue
      [SDKD(WARNING) 5.53 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM com.couchbase.client.CouchbaseClient <init>
      [SDKD(WARNING) 5.53 cbsdk.sdkd.remote remote.py:266] INFO: viewmode property isn't defined. Setting viewmode to production mode
      [SDKD(WARNING) 5.53 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM net.spy.memcached.MemcachedConnection handleIO
      [SDKD(WARNING) 5.53 cbsdk.sdkd.remote remote.py:266] INFO: Connection state changed for sun.nio.ch.SelectionKeyImpl@6d79953c
      [SDKD(WARNING) 5.53 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM net.spy.memcached.MemcachedConnection handleIO
      [SDKD(WARNING) 5.53 cbsdk.sdkd.remote remote.py:266] INFO: Connection state changed for sun.nio.ch.SelectionKeyImpl@4934ce4a
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM net.spy.memcached.MemcachedConnection queueReconnect
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] WARNING: Closing, and reopening

      {QA sa=/10.2.1.101:11210, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null, toWrite=0, interested=8}

      , attempt 1.
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM net.spy.memcached.MemcachedConnection handleIO
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] INFO: Reconnecting due to failure to connect to

      {QA sa=/10.2.1.101:11210, #Rops=0, #Wops=1, #iq=0, topRop=null, topWop=Cmd: 10 Opaque: 55, toWrite=0, interested=0}


      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] java.net.ConnectException: Could not send noop upon connect! This may indicate a running, but not responding memcached instance.
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:439)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:247)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at com.couchbase.client.CouchbaseMemcachedConnection.run(CouchbaseMemcachedConnection.java:158)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM net.spy.memcached.MemcachedConnection queueReconnect
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] WARNING: Closing, and reopening

      {QA sa=/10.2.1.101:11210, #Rops=0, #Wops=1, #iq=0, topRop=null, topWop=Cmd: 10 Opaque: 55, toWrite=0, interested=0}

      , attempt 1.
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM net.spy.memcached.MemcachedConnection queueReconnect
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] WARNING: Closing, and reopening

      {QA sa=/10.2.1.101:11210, #Rops=0, #Wops=1, #iq=0, topRop=null, topWop=Cmd: 10 Opaque: 55, toWrite=0, interested=0}

      , attempt 3.
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM net.spy.memcached.MemcachedConnection queueReconnect
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] INFO: The channel or socket was null for

      {QA sa=/10.2.1.101:11210, #Rops=0, #Wops=1, #iq=0, topRop=null, topWop=Cmd: 10 Opaque: 55, toWrite=0, interested=0}


      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] Exception in thread "SDK Handle-14" java.lang.NullPointerException
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at net.spy.memcached.MemcachedConnection.queueReconnect(MemcachedConnection.java:589)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at com.couchbase.client.CouchbaseMemcachedConnection.reconfigure(CouchbaseMemcachedConnection.java:132)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at com.couchbase.client.CouchbaseClient.reconfigure(CouchbaseClient.java:273)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at com.couchbase.client.vbucket.ReconfigurableObserver.update(ReconfigurableObserver.java:54)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at java.util.Observable.notifyObservers(Observable.java:159)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at com.couchbase.client.vbucket.BucketMonitor.setBucket(BucketMonitor.java:258)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at com.couchbase.client.vbucket.BucketMonitor.startMonitor(BucketMonitor.java:188)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at com.couchbase.client.vbucket.ConfigurationProviderHTTP.subscribe(ConfigurationProviderHTTP.java:288)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at com.couchbase.client.CouchbaseClient.<init>(CouchbaseClient.java:246)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at com.couchbase.sdkd.SdkdConfig.getClient(SdkdConfig.java:99)
      [SDKD(WARNING) 5.55 cbsdk.sdkd.remote remote.py:266] at com.couchbase.sdkd.cbclient.Handle.<init>(Handle.java:159)
      [SDKD(WARNING) 5.59 cbsdk.sdkd.remote remote.py:266] at com.couchbase.sdkd.server.SdkServer.executeCommand(SdkServer.java:104)
      [SDKD(WARNING) 5.59 cbsdk.sdkd.remote remote.py:266] at com.couchbase.sdkd.server.SdkServer.handleRequest(SdkServer.java:189)
      [SDKD(WARNING) 5.59 cbsdk.sdkd.remote remote.py:266] at com.couchbase.sdkd.server.SdkServer.run(SdkServer.java:245)
      [SDKD(WARNING) 5.59 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:20 PM net.spy.memcached.auth.AuthThread$1 receivedStatus
      [SDKD(WARNING) 5.59 cbsdk.sdkd.remote remote.py:266] INFO: Authenticated to /10.2.1.102:11210
      [SDKD(WARNING) 13.55 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:28 PM net.spy.memcached.MemcachedConnection attemptReconnects
      [SDKD(WARNING) 13.55 cbsdk.sdkd.remote remote.py:266] INFO: Reconnecting

      {QA sa=/10.2.1.101:11210, #Rops=0, #Wops=1, #iq=0, topRop=null, topWop=Cmd: 10 Opaque: 55, toWrite=0, interested=0}

      [SDKD(WARNING) 13.55 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:28 PM net.spy.memcached.MemcachedConnection handleIO
      [SDKD(WARNING) 13.55 cbsdk.sdkd.remote remote.py:266] INFO: Connection state changed for sun.nio.ch.SelectionKeyImpl@79884a40
      [SDKD(WARNING) 13.56 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:28 PM net.spy.memcached.auth.AuthThread$1 receivedStatus
      [SDKD(WARNING) 13.56 cbsdk.sdkd.remote remote.py:266] INFO: Authenticated to /10.2.1.101:11210
      [SDKD(WARNING) 21.55 cbsdk.sdkd.remote remote.py:266] Mar 8, 2013 5:39:36 PM net.spy.memcached.MemcachedConnection attemptReconnects
      [SDKD(WARNING) 21.55 cbsdk.sdkd.remote remote.py:266] INFO: Reconnecting

      {QA sa=/10.2.1.101:11210, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null, toWrite=0, interested=0}

      [SDKD(WARNING) 21.55 cbsdk.sdkd.remote remote.py:266] Exception in thread "Memcached IO over

      {MemcachedConnection to /10.2.1.102:11210 /10.2.1.101:11210}

      " java.lang.AssertionError: Attempting to overwrite channel
      [SDKD(WARNING) 21.55 cbsdk.sdkd.remote remote.py:266] at net.spy.memcached.protocol.TCPMemcachedNodeImpl.setChannel(TCPMemcachedNodeImpl.java:496)
      [SDKD(WARNING) 21.55 cbsdk.sdkd.remote remote.py:266] at net.spy.memcached.protocol.TCPMemcachedNodeImpl.registerChannel(TCPMemcachedNodeImpl.java:484)
      [SDKD(WARNING) 21.55 cbsdk.sdkd.remote remote.py:266] at net.spy.memcached.MemcachedConnection.attemptReconnects(MemcachedConnection.java:680)
      [SDKD(WARNING) 21.55 cbsdk.sdkd.remote remote.py:266] at net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:262)
      [SDKD(WARNING) 21.55 cbsdk.sdkd.remote remote.py:266] at com.couchbase.client.CouchbaseMemcachedConnection.run(CouchbaseMemcachedConnection.java:158)

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

        Activity

        Hide
        daschl Michael Nitschinger added a comment -

        Hey Mark,

        i just stumbled across this ticket. Did you try to connect with a CouchbaseClient against a vanilla memcached instance? That wont work obviously.

        Show
        daschl Michael Nitschinger added a comment - Hey Mark, i just stumbled across this ticket. Did you try to connect with a CouchbaseClient against a vanilla memcached instance? That wont work obviously.
        Hide
        daschl Michael Nitschinger added a comment -

        Never seen this again, closing for now.

        Show
        daschl Michael Nitschinger added a comment - Never seen this again, closing for now.

          People

          • Assignee:
            mnunberg Mark Nunberg
            Reporter:
            mnunberg Mark Nunberg
          • Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Gerrit Reviews

              There are no open Gerrit changes