roc230 / spymemcached

Automatically exported from code.google.com/p/spymemcached
0 stars 0 forks source link

Deadlock when trying to addListener to a GetFuture #300

Open GoogleCodeExporter opened 9 years ago

GoogleCodeExporter commented 9 years ago
Using spymemcached 2.10.6

Here is a thread dump:

 Found one Java-level deadlock:
 =============================
 "instance-tpe-0":
   waiting to lock monitor 0x0000000002476038 (object 0x0000000787d65d18, a net.spy.memcached.protocol.ascii.StoreOperationImpl),
   which is held by "Memcached IO over {MemcachedConnection to HOSTNAME:11211 HOSTNAME2:11211 HOSTNAME3:11211}"
 "Memcached IO over {MemcachedConnection to HOSTNAME:11211 HOSTNAME2:11211 HOSTNAME3:11211}":
   waiting to lock monitor 0x0000000002472470 (object 0x0000000787d65d80, a net.spy.memcached.internal.OperationFuture),
   which is held by "instance-tpe-0"

 Java stack information for the threads listed above:
 ===================================================
 "instance-tpe-0":
     at net.spy.memcached.protocol.BaseOperationImpl.isCancelled(BaseOperationImpl.java:88)
     - waiting to lock <0x0000000787d65d18> (a net.spy.memcached.protocol.ascii.StoreOperationImpl)
     at net.spy.memcached.internal.OperationFuture.isDone(OperationFuture.java:305)
     at net.spy.memcached.internal.AbstractListenableFuture.addToListeners(AbstractListenableFuture.java:93)
     - locked <0x0000000787d65d80> (a net.spy.memcached.internal.OperationFuture)
     at net.spy.memcached.internal.OperationFuture.addListener(OperationFuture.java:311)
 "Memcached IO over {MemcachedConnection to HOSTNAME:11211 HOSTNAME2:11211 HOSTNAME3:11211}":
     at net.spy.memcached.internal.AbstractListenableFuture.notifyListeners(AbstractListenableFuture.java:144)
     - waiting to lock <0x0000000787d65d80> (a net.spy.memcached.internal.OperationFuture)
     at net.spy.memcached.internal.AbstractListenableFuture.notifyListeners(AbstractListenableFuture.java:130)
     at net.spy.memcached.internal.OperationFuture.signalComplete(OperationFuture.java:326)
     at net.spy.memcached.MemcachedClient$1.complete(MemcachedClient.java:322)
     at net.spy.memcached.protocol.BaseOperationImpl.transitionState(BaseOperationImpl.java:142)
     - locked <0x0000000787d65d18> (a net.spy.memcached.protocol.ascii.StoreOperationImpl)
     at net.spy.memcached.protocol.ascii.BaseStoreOperationImpl.handleLine(BaseStoreOperationImpl.java:64)
     at net.spy.memcached.protocol.ascii.OperationImpl.readFromBuffer(OperationImpl.java:154)
     at net.spy.memcached.MemcachedConnection.readBufferAndLogMetrics(MemcachedConnection.java:813)
     at net.spy.memcached.MemcachedConnection.handleReads(MemcachedConnection.java:792)
     - locked <0x0000000787d65d18> (a net.spy.memcached.protocol.ascii.StoreOperationImpl)
     at net.spy.memcached.MemcachedConnection.handleReadsAndWrites(MemcachedConnection.java:672)
     at net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:635)
     at net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:409)
     at net.spy.memcached.MemcachedConnection.run(MemcachedConnection.java:1348)

 Found 1 deadlock.

Original issue reported on code.google.com by k...@spotify.com on 20 Mar 2014 at 9:49

GoogleCodeExporter commented 9 years ago
Thanks for reporting this, I'll take a look soon.

Do you have any code that reliably reproduces this?

Original comment by michael....@gmail.com on 20 Mar 2014 at 9:53

GoogleCodeExporter commented 9 years ago
I can't share the exact code as it's proprietary but here's something that's 
close enough:

The client is created like this:
  client = new net.spy.memcached.MemcachedClient(new KetamaConnectionFactory(), hosts)
and the host is a list of three machines, where one of them is on localhost.

    final OperationFuture<Boolean> future = this.client.set(key, ttlSec, value, transcoder);
    future.addListener( // Here is where it deadlocks
      new OperationCompletionListener() {

        @Override
        public void onComplete(final OperationFuture<?> ignored) throws Exception {
           // do stuff
        }
      });

Our usage pattern is mostly gets and occasional puts.

Original comment by k...@spotify.com on 20 Mar 2014 at 9:58

GoogleCodeExporter commented 9 years ago
I forgot to mention that we were previously running 2.10.0 without any issues, 
so the bug was probably introduced between 2.10.1 and 2.10.6.

I looked a bit at the recent changes and maybe this change introduced this bug?
http://www.couchbase.com/issues/browse/SPY-155

I have no strong argument for that, other then that it introduces a lock and 
correlates somewhat in time.

Original comment by k...@spotify.com on 20 Mar 2014 at 10:03

GoogleCodeExporter commented 9 years ago
hmm that could very well be.. thanks for the pointer, I'll figure it out I 
hope..

btw the sync was added because we had reports that the listener was sometimes 
never called

Original comment by michael....@gmail.com on 20 Mar 2014 at 10:13

GoogleCodeExporter commented 9 years ago
looks like someone else hit the same issue, currently investigating again.

Hope to have a fix for 2.11.2.

Original comment by michael....@gmail.com on 23 Apr 2014 at 2:56

GoogleCodeExporter commented 9 years ago
[deleted comment]
GoogleCodeExporter commented 9 years ago
Same here on 2.10.6

Original comment by tovbinm@gmail.com on 29 Apr 2014 at 12:24

Attachments:

GoogleCodeExporter commented 9 years ago
Here my code snippet in Scala, but should readable:

val promise: Promise[T] = ...
val future = memcached.asyncGet(...)
future.addListener(new GetCompletionListener {
  def onComplete(future: GetFuture[_]) = promise.complete( Try { future.get().asInstanceOf[T] } )
})

Original comment by tovbinm@gmail.com on 29 Apr 2014 at 3:01

GoogleCodeExporter commented 9 years ago
Thanks, we already have a fix pending for the next bugfix release! Should go 
out this or next week.
Cheers
Michael

Original comment by michael....@gmail.com on 5 May 2014 at 6:16

GoogleCodeExporter commented 9 years ago
Any status updates? Is it fixed in 2.11.4?

Original comment by k...@spotify.com on 24 Sep 2014 at 9:45