Uploaded image for project: 'C Driver'
  1. C Driver
  2. CDRIVER-1216

SDAM performance assumption incorrect on zSeries

    XMLWordPrintableJSON

Details

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major - P3 Major - P3
    • 1.4.0
    • None
    • libmongoc
    • None

    Description

      The test_seed_list() (connection_option_t=CONNECT|RECONNECT) tests all fail on zSeries.

       
         if (connection_option == CONNECT || connection_option == RECONNECT) {
            start = bson_get_monotonic_time ();
       
            /* only localhost:port responds to initial discovery. the other seeds are
             * discarded from replica set topology, but remain for sharded. */
            ASSERT_OR_PRINT (mongoc_client_command_simple (
               client, "test", tmp_bson("{'foo': 1}"),
               primary_pref, &reply, &error), error);
       
            /* discovery should be quick despite down servers, say < 100ms */
            duration_usec = bson_get_monotonic_time () - start;
            ASSERT_CMPTIME ((int) (duration_usec / 1000), 100);
      /* .... */
      }
      

      This almost always fail with the values ranging between 100 and 350.
      In rare cases they pass.

      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       stream: TRACE: mongoc_stream_writev():161 writev = 0x83fbc310 [9]
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       stream: 00000:  3a 00 00 00 04 00 00 00  00 00 00 00 d4 07 00 00  : . . . . . . .  . . . . . . . .
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       stream: 00010:  04 00 00 00 61 64 6d 69  6e 2e 24 63 6d 64 00 00  . . . . a d m i  n . $ c m d . .
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       stream: 00020:  00 00 00 ff ff ff ff 13  00 00 00 10 69 73 4d 61  . . . . . . . .  . . . . i s M a
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       stream: 00030:  73 74 65 72 00 01 00 00  00 00                    s t e r . . . .  . .
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       stream: ENTRY: _mongoc_stream_socket_writev():202
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: ENTRY: mongoc_socket_sendv():1089
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: ENTRY: _mongoc_socket_try_sendv():998
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: _mongoc_socket_try_sendv():1004 sendbuf = 0x83fbd290 [9]
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: 00000:  3a 00 00 00 04 00 00 00  00 00 00 00 d4 07 00 00  : . . . . . . .  . . . . . . . .
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: 00010:  04 00 00 00 61 64 6d 69  6e 2e 24 63 6d 64 00 00  . . . . a d m i  n . $ c m d . .
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: 00020:  00 00 00 ff ff ff ff 13  00 00 00 10 69 73 4d 61  . . . . . . . .  . . . . i s M a
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: 00030:  73 74 65 72 00 01 00 00  00 00                    s t e r . . . .  . .
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: _mongoc_socket_try_sendv():1020 Send 58 out of 4 bytes
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket:  EXIT: _mongoc_socket_try_sendv():1050
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_sendv():1100 Sent 58 (of 4) out of iovcnt=9
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_sendv():1125 still got bytes left: sent -= iov_len: 58 -= 4
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_sendv():1125 still got bytes left: sent -= iov_len: 54 -= 4
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_sendv():1125 still got bytes left: sent -= iov_len: 50 -= 4
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_sendv():1125 still got bytes left: sent -= iov_len: 46 -= 4
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_sendv():1125 still got bytes left: sent -= iov_len: 42 -= 4
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_sendv():1125 still got bytes left: sent -= iov_len: 38 -= 11
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_sendv():1125 still got bytes left: sent -= iov_len: 27 -= 4
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_sendv():1125 still got bytes left: sent -= iov_len: 23 -= 4
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_sendv():1125 still got bytes left: sent -= iov_len: 19 -= 19
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_sendv():1134 Finished the iovecs
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket:  EXIT: mongoc_socket_sendv():1165
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: TRACE: mongoc_socket_errno():307 Current errno: 115
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       stream:  EXIT: _mongoc_stream_socket_writev():208
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       stream:  EXIT: mongoc_stream_writev():164
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       stream: ENTRY: _mongoc_stream_socket_poll():226
      2016/04/29 17:48:39.0986: [ 7458]:    TRACE:       socket: ENTRY: mongoc_socket_poll():217
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket: ENTRY: _mongoc_socket_wait():113
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket:  EXIT: _mongoc_socket_wait():154
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket:  GOTO: mongoc_socket_accept_ex():442 again
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket: TRACE: _mongoc_socket_capture_errno():336 setting errno: 0
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket: ENTRY: _mongoc_socket_setnodelay():271
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket:  EXIT: _mongoc_socket_setnodelay():283
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket:  EXIT: mongoc_socket_accept_ex():467
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket: ENTRY: mongoc_socket_accept_ex():424
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket: TRACE: _mongoc_socket_capture_errno():336 setting errno: 11
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket: TRACE: _mongoc_socket_errno_is_again():360 errno is: 11
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket: ENTRY: _mongoc_socket_wait():113
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket:  EXIT: _mongoc_socket_wait():174
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket:  EXIT: mongoc_socket_accept_ex():444
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket: ENTRY: mongoc_socket_accept_ex():424
      2016/04/29 17:48:39.0986: [ 7473]:    TRACE:       socket: TRACE: _mongoc_socket_errno_is_again():360 errno is: 11
      2016/04/29 17:48:39.0986: [ 7472]:    TRACE:       socket: TRACE: _mongoc_socket_capture_errno():336 setting errno: 11
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket: TRACE: _mongoc_socket_errno_is_again():360 errno is: 11
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket: ENTRY: _mongoc_socket_wait():113
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket:  EXIT: _mongoc_socket_wait():154
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket:  GOTO: mongoc_socket_accept_ex():442 again
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket: TRACE: _mongoc_socket_capture_errno():336 setting errno: 0
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket: ENTRY: _mongoc_socket_setnodelay():271
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket:  EXIT: _mongoc_socket_setnodelay():283
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket:  EXIT: mongoc_socket_accept_ex():467
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket: ENTRY: mongoc_socket_accept_ex():424
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket: TRACE: _mongoc_socket_capture_errno():336 setting errno: 11
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket: TRACE: _mongoc_socket_errno_is_again():360 errno is: 11
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket: ENTRY: _mongoc_socket_wait():113
      2016/04/29 17:48:39.0986: [ 7475]:    TRACE:       socket:  EXIT: _mongoc_socket_wait():174
      

      ....

      2016/04/29 17:48:40.0101: [ 7472]:    TRACE:       socket:  EXIT: mongoc_socket_accept_ex():444
      2016/04/29 17:48:40.0101: [ 7472]:    TRACE:       socket: ENTRY: mongoc_socket_accept_ex():424
      2016/04/29 17:48:40.0101: [ 7472]:    TRACE:       socket: TRACE: _mongoc_socket_capture_errno():336 setting errno: 11
      2016/04/29 17:48:40.0101: [ 7472]:    TRACE:       socket: TRACE: _mongoc_socket_errno_is_again():360 errno is: 11
      2016/04/29 17:48:40.0101: [ 7472]:    TRACE:       socket: ENTRY: _mongoc_socket_wait():113
      2016/04/29 17:48:40.0101: [ 7472]:    TRACE:       socket:  EXIT: _mongoc_socket_wait():174
      2016/04/29 17:48:40.0101: [ 7472]:    TRACE:       socket:  EXIT: mongoc_socket_accept_ex():444
      2016/04/29 17:48:40.0101: [ 7472]:    TRACE:       socket: ENTRY: mongoc_socket_accept_ex():424
      2016/04/29 17:48:40.0101: [ 7472]:    TRACE:       socket: TRACE: _mongoc_socket_capture_errno():336 setting errno: 11
      2016/04/29 17:48:40.0101: [ 7472]:    TRACE:       socket: TRACE: _mongoc_socket_errno_is_again():360 errno is: 11
      

      ....

      2016/04/29 17:48:40.0145: [ 7475]:    TRACE:       socket:  EXIT: mongoc_socket_accept_ex():444
      2016/04/29 17:48:40.0145: [ 7475]:    TRACE:       socket: ENTRY: mongoc_socket_accept_ex():424
      2016/04/29 17:48:40.0145: [ 7476]:    TRACE:       stream: ENTRY: mongoc_stream_readv():226
      2016/04/29 17:48:40.0145: [ 7475]:    TRACE:       socket: TRACE: _mongoc_socket_capture_errno():336 setting errno: 11
      2016/04/29 17:48:40.0145: [ 7476]:    TRACE:       stream: ENTRY: _mongoc_stream_socket_readv():139
      2016/04/29 17:48:40.0145: [ 7476]:    TRACE:       socket: ENTRY: mongoc_socket_recv():797
      2016/04/29 17:48:40.0145: [ 7479]:    TRACE:       buffer: ENTRY: _mongoc_buffer_fill():211
      2016/04/29 17:48:40.0145: [ 7477]:    TRACE:       stream: 002b0:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7475]:    TRACE:       socket: TRACE: _mongoc_socket_errno_is_again():360 errno is: 11
      2016/04/29 17:48:40.0145: [ 7475]:    TRACE:       socket: ENTRY: _mongoc_socket_wait():113
      2016/04/29 17:48:40.0145: [ 7474]:    TRACE:       socket:  EXIT: mongoc_socket_accept_ex():444
      2016/04/29 17:48:40.0145: [ 7474]:    TRACE:       socket: ENTRY: mongoc_socket_accept_ex():424
      2016/04/29 17:48:40.0145: [ 7479]:    TRACE:       stream: ENTRY: mongoc_stream_read():268
      2016/04/29 17:48:40.0145: [ 7474]:    TRACE:       socket: TRACE: _mongoc_socket_capture_errno():336 setting errno: 11
      2016/04/29 17:48:40.0145: [ 7474]:    TRACE:       socket: TRACE: _mongoc_socket_errno_is_again():360 errno is: 11
      2016/04/29 17:48:40.0145: [ 7474]:    TRACE:       socket: ENTRY: _mongoc_socket_wait():113
      2016/04/29 17:48:40.0145: [ 7474]:    TRACE:       socket:  EXIT: _mongoc_socket_wait():174
      2016/04/29 17:48:40.0145: [ 7478]:    TRACE:       stream:  EXIT: _mongoc_stream_socket_readv():178
      2016/04/29 17:48:40.0145: [ 7477]:    TRACE:       stream: 002c0:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7478]:    TRACE:       stream: TRACE: mongoc_stream_readv():236 readv = 0x3ff6f7feb58 [1]
      2016/04/29 17:48:40.0145: [ 7477]:    TRACE:       stream: 002d0:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7478]:    TRACE:       stream: 00000:  3a 00 00 00 02 00 00 00  00 00 00 00 d4 07 00 00  : . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7477]:    TRACE:       stream: 002e0:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7477]:    TRACE:       stream: 002f0:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7478]:    TRACE:       stream: 00010:  04 00 00 00 61 64 6d 69  6e 2e 24 63 6d 64 00 00  . . . . a d m i  n . $ c m d . .
      2016/04/29 17:48:40.0145: [ 7477]:    TRACE:       stream: 00300:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7478]:    TRACE:       stream: 00020:  00 00 00 ff ff ff ff 13  00 00 00 10 69 73 4d 61  . . . . . . . .  . . . . i s M a
      2016/04/29 17:48:40.0145: [ 7477]:    TRACE:       stream: 00310:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7478]:    TRACE:       stream: 00030:  73 74 65 72 00 01 00 00  00 00 00 00 00 00 00 00  s t e r . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7477]:    TRACE:       stream: 00320:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7478]:    TRACE:       stream: 00040:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7477]:    TRACE:       stream: 00330:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7478]:    TRACE:       stream: 00050:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7477]:    TRACE:       stream: 00340:  00 00 00 00 00 00 00 00  00 00 00 00 00 00 00 00  . . . . . . . .  . . . . . . . .
      2016/04/29 17:48:40.0145: [ 7473]:    TRACE:       socket:  EXIT: _mongoc_socket_wait():174
      

      Attachments

        Activity

          People

            jesse@mongodb.com A. Jesse Jiryu Davis
            bjori Hannes Magnusson
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: