From d29fea258f6595922b19667efd39a41611d0c0ec Mon Sep 17 00:00:00 2001 From: Lars Mikkelsen Date: Mon, 23 Jan 2017 21:04:12 -0500 Subject: [PATCH] NPE in fillWriteBuffer() with binary protocol I apologize for using a PR to report an issue, but I'm unable to find a public issue tracker for spymemcached. Under certain circumstances `TCPMemcachedNodeImpl.fillWriteBuffer()` will throw a NullPointerException because the current write operation has transitioned to the `COMPLETE` state and thus doesn't have a write buffer. This issue has previously been reported in couchbase/spymemcached#16 and https://code.google.com/archive/p/spymemcached/issues/304. I'm able to consistently reproduce the issue using spymemcached 1.12.1 and memcached 1.4.34 installed using Homebrew on macOS 10.12.2. The daemon is running with the default options (`memcached -l localhost`). I'm running the included `Main.java` with the 1.12.1 release JAR: ``` $ javac -classpath spymemcached-2.12.1.jar Main.java $ java -cp spymemcached-2.12.1.jar:. Main ``` It consistently produces the following output: ``` 2017-01-23 20:40:24.678 INFO net.spy.memcached.MemcachedConnection: Added {QA sa=localhost/127.0.0.1:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null, toWrite=0, interested=0} to connect queue 2017-01-23 20:40:25.170 INFO net.spy.memcached.MemcachedConnection: Reconnecting due to exception on {QA sa=localhost/127.0.0.1:11211, #Rops=0, #Wops=155, #iq=6, topRop=null, topWop=Cmd: 1 Opaque: 81 Key: test Cas: 0 Exp: 60 Flags: 2048 Data Length: 2097152, toWrite=0, interested=5} java.lang.NullPointerException at net.spy.memcached.protocol.TCPMemcachedNodeImpl.fillWriteBuffer(TCPMemcachedNodeImpl.java:206) at net.spy.memcached.MemcachedConnection.handleWrites(MemcachedConnection.java:800) at net.spy.memcached.MemcachedConnection.handleReadsAndWrites(MemcachedConnection.java:723) at net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:683) at net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:436) at net.spy.memcached.MemcachedConnection.run(MemcachedConnection.java:1446) 2017-01-23 20:40:25.172 WARN net.spy.memcached.MemcachedConnection: Closing, and reopening {QA sa=localhost/127.0.0.1:11211, #Rops=0, #Wops=155, #iq=9, topRop=null, topWop=Cmd: 1 Opaque: 81 Key: test Cas: 0 Exp: 60 Flags: 2048 Data Length: 2097152, toWrite=0, interested=5}, attempt 0. 2017-01-23 20:40:25.173 INFO net.spy.memcached.protocol.binary.BinaryMemcachedNodeImpl: No buffer for current write op, removing 2017-01-23 20:40:25.173 WARN net.spy.memcached.MemcachedConnection: Could not redistribute to another node, retrying primary node for test. 2017-01-23 20:40:25.174 WARN net.spy.memcached.MemcachedConnection: Could not redistribute to another node, retrying primary node for test. 2017-01-23 20:40:25.175 WARN net.spy.memcached.MemcachedConnection: Could not redistribute to another node, retrying primary node for test. ``` Occasionally the IO thread dies: ``` 2017-01-23 20:40:27.116 INFO net.spy.memcached.MemcachedConnection: Added {QA sa=localhost/127.0.0.1:11211, #Rops=0, #Wops=0, #iq=0, topRop=null, topWop=null, toWrite=0, interested=0} to connect queue Exception in thread "Memcached IO over {MemcachedConnection to localhost/127.0.0.1:11211}" java.lang.NullPointerException at net.spy.memcached.protocol.TCPMemcachedNodeImpl.fillWriteBuffer(TCPMemcachedNodeImpl.java:206) at net.spy.memcached.MemcachedConnection.handleWrites(MemcachedConnection.java:800) at net.spy.memcached.MemcachedConnection.handleInputQueue(MemcachedConnection.java:582) at net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:409) at net.spy.memcached.MemcachedConnection.run(MemcachedConnection.java:1446) ``` As far as I can tell the condition occurs when `MemcachedConnection.handleWrites()` exits before having written all of the current operation because the buffer is full. If the operation causes the daemon to return an error `OperationImpl.finishedPayload()` will transition the operation to the `COMPLETE` state (which sets the buffer to null). Since the operation isn't removed from the write queue a NullPointerException is thrown on the next `handleWrites()`. I'm using a large (2MB) data object to trigger an `ERR_2BIG` error, but I believe the condition could happen with any of the `ERR_BUSY`, `ERR_TEMP_FAIL`, etc. errors as well: https://github.com/couchbase/spymemcached/blob/2.12.1/src/main/java/net/spy/memcached/protocol/binary/OperationImpl.java#L244-L252 --- Main.java | 23 +++++++++++++++++++++++ 1 file changed, 23 insertions(+) create mode 100644 Main.java diff --git a/Main.java b/Main.java new file mode 100644 index 000000000..646e17b0b --- /dev/null +++ b/Main.java @@ -0,0 +1,23 @@ +import java.io.IOException; +import java.net.InetSocketAddress; +import java.util.Arrays; +import java.util.List; + +import net.spy.memcached.BinaryConnectionFactory; +import net.spy.memcached.MemcachedClient; +import net.spy.memcached.transcoders.SerializingTranscoder; + +public class Main { + public static void main(String[] args) throws IOException { + List addrs = Arrays.asList(new InetSocketAddress("localhost", 11211)); + MemcachedClient client = new MemcachedClient(new BinaryConnectionFactory(), addrs); + + SerializingTranscoder transcoder = new SerializingTranscoder(); + transcoder.setCompressionThreshold(Integer.MAX_VALUE); + + byte[] data = new byte[2 * 1024 * 1024]; + while (true) { + client.set("test", 60, data, transcoder); + } + } +}