[JAVA-2278] Different behaviour in async driver with different streams Created: 12/Aug/16  Updated: 11/Sep/19  Resolved: 29/Sep/17

Status: Closed
Project: Java Driver
Component/s: Async
Affects Version/s: 3.3.0
Fix Version/s: None

Type: Task Priority: Major - P3
Reporter: Sergey Polovko Assignee: Unassigned
Resolution: Won't Fix Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified
Environment:

OSX 10.11 / Ubuntu 14.04
Java 8
MongoDB Server: 3.2.7
mongo-java-driver: HEAD



 Description   

I use async java driver to perform insertions into mongo replicaset with three nodes.
When I kill primary mongo server I see different behaviour with different stream implementation (NettyStream or AsynchronousSocketChannelStream).
With NettyStream several insert requests fails immediately with MongoSocketOpenException: Exception opening socket after primary killing. But with AsynchronousSocketChannelStream no insert requests filed with such exception, all of them are buffered and after primary election completed they actually performed with no errors.

Simple example to reproduce:

import java.io.OutputStream;
import java.io.PrintStream;
import java.util.Date;
 
import com.mongodb.async.SingleResultCallback;
import com.mongodb.async.client.MongoClient;
import com.mongodb.async.client.MongoClients;
import com.mongodb.async.client.MongoCollection;
import com.mongodb.async.client.MongoDatabase;
import org.bson.Document;
 
 
public class StreamTypeTest {
 
    static {
        System.setErr(new PrintStream(new OutputStream() {
            public void write(int b) {
                //DO NOTHING
            }
        }));
    }
 
    public static void main(String[] args) {
        String streamType = "nio2"; // nio2
 
        MongoClient client = MongoClients.create(
                "mongodb://localhost:27017,localhost:27018,localhost:27019/?streamType=" + streamType);
        MongoDatabase db = client.getDatabase("test");
 
        MongoCollection<Document> col1 = db.getCollection("col1");
 
        for (int i = 0; ; i++) {
            final int index = i;
 
            System.out.println(new Date() + ": inserting" + index);
 
            col1.insertOne(new Document("key", "value"), new SingleResultCallback<Void>() {
                @Override
                public void onResult(final Void result, final Throwable t) {
                    if (t != null) {
                        System.out.println(new Date() + ": not inserted" + index + ": " + t.getMessage());
                    } else {
                        System.out.println(new Date() + ": inserted" + index);
                    }
                }
            });
 
            try {
                Thread.sleep(500);
            } catch (InterruptedException e) {
                e.printStackTrace();
                break;
            }
        }
    }
}

With streamType == "netty" I get:

Fri Aug 12 17:08:30 MSK 2016: inserting0
Fri Aug 12 17:08:31 MSK 2016: inserted0
Fri Aug 12 17:08:31 MSK 2016: inserting1
Fri Aug 12 17:08:31 MSK 2016: inserted1
Fri Aug 12 17:08:32 MSK 2016: inserting2
Fri Aug 12 17:08:32 MSK 2016: inserted2
Fri Aug 12 17:08:32 MSK 2016: inserting3
Fri Aug 12 17:08:32 MSK 2016: inserted3
Fri Aug 12 17:08:33 MSK 2016: inserting4
Fri Aug 12 17:08:33 MSK 2016: inserted4
Fri Aug 12 17:08:33 MSK 2016: inserting5
 
<< here I kill primary mongo server >>
 
Fri Aug 12 17:08:34 MSK 2016: inserting6
Fri Aug 12 17:08:34 MSK 2016: not inserted6: Exception receiving message
Fri Aug 12 17:08:34 MSK 2016: inserting7
Fri Aug 12 17:08:34 MSK 2016: not inserted7: Exception opening socket
Fri Aug 12 17:08:35 MSK 2016: inserting8
Fri Aug 12 17:08:35 MSK 2016: not inserted8: Exception opening socket
Fri Aug 12 17:08:35 MSK 2016: inserting9
Fri Aug 12 17:08:35 MSK 2016: not inserted9: Exception opening socket
Fri Aug 12 17:08:36 MSK 2016: inserting10
Fri Aug 12 17:08:36 MSK 2016: not inserted10: Exception opening socket
Fri Aug 12 17:08:36 MSK 2016: inserting11
Fri Aug 12 17:08:36 MSK 2016: not inserted11: Exception opening socket
Fri Aug 12 17:08:37 MSK 2016: inserting12
Fri Aug 12 17:08:37 MSK 2016: not inserted12: Exception opening socket
Fri Aug 12 17:08:37 MSK 2016: inserting13
Fri Aug 12 17:08:37 MSK 2016: not inserted13: Exception opening socket
Fri Aug 12 17:08:38 MSK 2016: inserting14
Fri Aug 12 17:08:38 MSK 2016: not inserted14: Exception opening socket
Fri Aug 12 17:08:38 MSK 2016: inserting15
Fri Aug 12 17:08:38 MSK 2016: not inserted15: Exception opening socket
Fri Aug 12 17:08:39 MSK 2016: inserting16
Fri Aug 12 17:08:39 MSK 2016: not inserted16: Exception opening socket
Fri Aug 12 17:08:39 MSK 2016: inserting17
Fri Aug 12 17:08:39 MSK 2016: not inserted17: Exception opening socket
Fri Aug 12 17:08:40 MSK 2016: inserting18
Fri Aug 12 17:08:40 MSK 2016: not inserted18: Exception opening socket
Fri Aug 12 17:08:40 MSK 2016: inserting19
Fri Aug 12 17:08:40 MSK 2016: not inserted19: Exception opening socket
Fri Aug 12 17:08:41 MSK 2016: inserting20
Fri Aug 12 17:08:41 MSK 2016: not inserted20: Exception opening socket
Fri Aug 12 17:08:41 MSK 2016: inserting21
Fri Aug 12 17:08:42 MSK 2016: inserting22
Fri Aug 12 17:08:42 MSK 2016: inserting23
Fri Aug 12 17:08:43 MSK 2016: inserting24
Fri Aug 12 17:08:43 MSK 2016: inserting25
Fri Aug 12 17:08:44 MSK 2016: inserting26
Fri Aug 12 17:08:44 MSK 2016: inserting27
Fri Aug 12 17:08:45 MSK 2016: inserting28
Fri Aug 12 17:08:45 MSK 2016: inserting29
Fri Aug 12 17:08:46 MSK 2016: inserting30
Fri Aug 12 17:08:46 MSK 2016: inserting31
Fri Aug 12 17:08:47 MSK 2016: inserting32
Fri Aug 12 17:08:47 MSK 2016: inserting33
Fri Aug 12 17:08:48 MSK 2016: inserting34
Fri Aug 12 17:08:48 MSK 2016: inserting35
Fri Aug 12 17:08:49 MSK 2016: inserting36
Fri Aug 12 17:08:49 MSK 2016: inserting37
Fri Aug 12 17:08:50 MSK 2016: inserting38
Fri Aug 12 17:08:50 MSK 2016: inserting39
Fri Aug 12 17:08:51 MSK 2016: inserting40
 
<< here election was completed >>
 
Fri Aug 12 17:08:51 MSK 2016: inserted22
Fri Aug 12 17:08:51 MSK 2016: inserted21
Fri Aug 12 17:08:51 MSK 2016: inserted23
Fri Aug 12 17:08:51 MSK 2016: inserted24
Fri Aug 12 17:08:51 MSK 2016: inserted25
Fri Aug 12 17:08:51 MSK 2016: inserted30
Fri Aug 12 17:08:51 MSK 2016: inserted29
Fri Aug 12 17:08:51 MSK 2016: inserted26
Fri Aug 12 17:08:51 MSK 2016: inserted34
Fri Aug 12 17:08:51 MSK 2016: inserted33
Fri Aug 12 17:08:51 MSK 2016: inserted38
Fri Aug 12 17:08:51 MSK 2016: inserted27
Fri Aug 12 17:08:51 MSK 2016: inserted32
Fri Aug 12 17:08:51 MSK 2016: inserted37
Fri Aug 12 17:08:51 MSK 2016: inserted35
Fri Aug 12 17:08:51 MSK 2016: inserted28
Fri Aug 12 17:08:51 MSK 2016: inserted36
Fri Aug 12 17:08:51 MSK 2016: inserted40
Fri Aug 12 17:08:51 MSK 2016: inserted31
Fri Aug 12 17:08:51 MSK 2016: inserted39
Fri Aug 12 17:08:51 MSK 2016: inserting41
Fri Aug 12 17:08:51 MSK 2016: inserted41
Fri Aug 12 17:08:52 MSK 2016: inserting42
Fri Aug 12 17:08:52 MSK 2016: inserted42
Fri Aug 12 17:08:52 MSK 2016: inserting43
Fri Aug 12 17:08:52 MSK 2016: inserted43
Fri Aug 12 17:08:53 MSK 2016: inserting44
Fri Aug 12 17:08:53 MSK 2016: inserted44

Fri Aug 12 17:12:02 MSK 2016: inserting0
Fri Aug 12 17:12:02 MSK 2016: inserted0
Fri Aug 12 17:12:03 MSK 2016: inserting1
Fri Aug 12 17:12:03 MSK 2016: inserted1
Fri Aug 12 17:12:03 MSK 2016: inserting2
Fri Aug 12 17:12:03 MSK 2016: inserted2
Fri Aug 12 17:12:04 MSK 2016: inserting3
Fri Aug 12 17:12:04 MSK 2016: inserted3
 
<< here I kill primary mongo server >>
 
Fri Aug 12 17:12:04 MSK 2016: inserting4
Fri Aug 12 17:12:04 MSK 2016: not inserted4: Prematurely reached end of stream
Fri Aug 12 17:12:05 MSK 2016: inserting5
Fri Aug 12 17:12:05 MSK 2016: inserting6
Fri Aug 12 17:12:06 MSK 2016: inserting7
Fri Aug 12 17:12:06 MSK 2016: inserting8
Fri Aug 12 17:12:07 MSK 2016: inserting9
Fri Aug 12 17:12:07 MSK 2016: inserting10
Fri Aug 12 17:12:08 MSK 2016: inserting11
Fri Aug 12 17:12:08 MSK 2016: inserting12
Fri Aug 12 17:12:09 MSK 2016: inserting13
Fri Aug 12 17:12:09 MSK 2016: inserting14
Fri Aug 12 17:12:10 MSK 2016: inserting15
Fri Aug 12 17:12:10 MSK 2016: inserting16
Fri Aug 12 17:12:11 MSK 2016: inserting17
Fri Aug 12 17:12:11 MSK 2016: inserting18
Fri Aug 12 17:12:12 MSK 2016: inserting19
Fri Aug 12 17:12:12 MSK 2016: inserting20
Fri Aug 12 17:12:13 MSK 2016: inserting21
Fri Aug 12 17:12:13 MSK 2016: inserting22
Fri Aug 12 17:12:14 MSK 2016: inserting23
Fri Aug 12 17:12:14 MSK 2016: inserting24
 
<< here election was completed >>
 
Fri Aug 12 17:12:15 MSK 2016: inserted5
Fri Aug 12 17:12:15 MSK 2016: inserted6
Fri Aug 12 17:12:15 MSK 2016: inserting25
Fri Aug 12 17:12:15 MSK 2016: inserted8
Fri Aug 12 17:12:15 MSK 2016: inserted7
Fri Aug 12 17:12:15 MSK 2016: inserted9
Fri Aug 12 17:12:15 MSK 2016: inserted25
Fri Aug 12 17:12:15 MSK 2016: inserted10
Fri Aug 12 17:12:15 MSK 2016: inserted11
Fri Aug 12 17:12:15 MSK 2016: inserted12
Fri Aug 12 17:12:15 MSK 2016: inserted13
Fri Aug 12 17:12:15 MSK 2016: inserted14
Fri Aug 12 17:12:15 MSK 2016: inserted15
Fri Aug 12 17:12:15 MSK 2016: inserted16
Fri Aug 12 17:12:15 MSK 2016: inserted18
Fri Aug 12 17:12:15 MSK 2016: inserted19
Fri Aug 12 17:12:15 MSK 2016: inserted17
Fri Aug 12 17:12:15 MSK 2016: inserted20
Fri Aug 12 17:12:15 MSK 2016: inserted22
Fri Aug 12 17:12:15 MSK 2016: inserted23
Fri Aug 12 17:12:15 MSK 2016: inserted21
Fri Aug 12 17:12:15 MSK 2016: inserted24
Fri Aug 12 17:12:15 MSK 2016: inserting26
Fri Aug 12 17:12:15 MSK 2016: inserted26
Fri Aug 12 17:12:16 MSK 2016: inserting27
Fri Aug 12 17:12:16 MSK 2016: inserted27
Fri Aug 12 17:12:16 MSK 2016: inserting28
Fri Aug 12 17:12:16 MSK 2016: inserted28
Fri Aug 12 17:12:17 MSK 2016: inserting29
Fri Aug 12 17:12:17 MSK 2016: inserted29
Fri Aug 12 17:12:17 MSK 2016: inserting30
Fri Aug 12 17:12:17 MSK 2016: inserted30



 Comments   
Comment by Ross Lawley [ 29/Sep/17 ]

Having tested on the latest version both stream types throw a MongoSocketException.

There is a difference in my testing; with Netty throwing a MongoSocketWriteException and nio2 a MongoSocketReadException. These different exceptions can be explained by the differences in how netty and nio2 are architected. In our stream abstraction we translate the read or write errors and pass them callback accordingly.

I'm marking this ticket as "Won't Fix" as there is no current plans to change this behaviour, especially as both throw a MongoSocketException.

Comment by Jeffrey Yemin [ 16/Sep/16 ]

As the driver makes no guarantees about this particular behavior, changing the issue type from bug to question.

Comment by Ross Lawley [ 22/Aug/16 ]

Thanks for the ticket jamel,

It's most likely a side effect of how the different underlying stream implementations work. I'll investigate more and feedback.

Ross

Generated at Thu Feb 08 08:56:48 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.