Uploaded image for project: 'Java Driver'
  1. Java Driver
  2. JAVA-2278

Different behaviour in async driver with different streams

    XMLWordPrintableJSON

Details

    • Icon: Task Task
    • Resolution: Won't Fix
    • Icon: Major - P3 Major - P3
    • None
    • 3.3.0
    • Async
    • None
    • 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
      

      Attachments

        Activity

          People

            Unassigned Unassigned
            jamel Sergey Polovko
            Votes:
            0 Vote for this issue
            Watchers:
            3 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: