-
Type: Bug
-
Resolution: Done
-
Priority: Major - P3
-
Affects Version/s: 1.0.0-beta1
-
Component/s: None
-
None
Streams don't appear to be cleanly killed on failure.
For example, on failed authentication the stream still sticks around, causing a "SSL/TLS already set-up for this stream" when attempting to authenticate again.
It also appears to be attempting to authenticate twice every for every stream:
[2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Connecting to '192.168.112.10:2300[mongodb://username@192.168.112.10:2300/phongo?ssl=true&authMechanism=MONGODB-X509]' [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Created: RSRC#9 as '192.168.112.10:2300[mongodb://username@192.168.112.10:2300/phongo?ssl=true&authMechanism=MONGODB-X509]' [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Enabling SSL [2015-09-11T21:31:35+00:00] PHONGO: TRACE > EXIT: phongo_stream_initiator():1282 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_writev():148 [2015-09-11T21:31:35+00:00] stream: TRACE > TRACE: mongoc_stream_writev():160 writev = 0x7f9d669fcf88 [9] [2015-09-11T21:31:35+00:00] stream: TRACE > 00000: 3a 00 00 00 01 00 00 00 00 00 00 00 d4 07 00 00 : . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 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 . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00020: 00 00 00 ff ff ff ff 13 00 00 00 10 69 73 4d 61 . . . . . . . . . . . . i s M a [2015-09-11T21:31:35+00:00] stream: TRACE > 00030: 73 74 65 72 00 01 00 00 00 00 s t e r . . . . . . [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Setting timeout to: 0 [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_writev():163 [2015-09-11T21:31:35+00:00] buffer: TRACE > ENTRY: _mongoc_buffer_try_append_from_stream():293 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_read():265 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_readv():225 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Setting timeout to: 0 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Reading got: 4 wanted: 0 [2015-09-11T21:31:35+00:00] stream: TRACE > TRACE: mongoc_stream_readv():234 readv = 0x7fff3371c200 [1] [2015-09-11T21:31:35+00:00] stream: TRACE > 00000: c2 00 00 00 . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_readv():236 [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_read():277 [2015-09-11T21:31:35+00:00] buffer: TRACE > EXIT: _mongoc_buffer_try_append_from_stream():323 [2015-09-11T21:31:35+00:00] buffer: TRACE > ENTRY: _mongoc_buffer_try_append_from_stream():293 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_read():265 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_readv():225 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Setting timeout to: 0 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Reading got: 190 wanted: 0 [2015-09-11T21:31:35+00:00] stream: TRACE > TRACE: mongoc_stream_readv():234 readv = 0x7fff3371c1d0 [1] [2015-09-11T21:31:35+00:00] stream: TRACE > 00000: c4 00 00 00 01 00 00 00 01 00 00 00 08 00 00 00 . . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00010: 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 . . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00020: 9e 00 00 00 08 69 73 6d 61 73 74 65 72 00 01 10 . . . . . i s m a s t e r . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00030: 6d 61 78 42 73 6f 6e 4f 62 6a 65 63 74 53 69 7a m a x B s o n O b j e c t S i z [2015-09-11T21:31:35+00:00] stream: TRACE > 00040: 65 00 00 00 00 01 10 6d 61 78 4d 65 73 73 61 67 e . . . . . . m a x M e s s a g [2015-09-11T21:31:35+00:00] stream: TRACE > 00050: 65 53 69 7a 65 42 79 74 65 73 00 00 6c dc 02 10 e S i z e B y t e s . . l . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00060: 6d 61 78 57 72 69 74 65 42 61 74 63 68 53 69 7a m a x W r i t e B a t c h S i z [2015-09-11T21:31:35+00:00] stream: TRACE > 00070: 65 00 e8 03 00 00 09 6c 6f 63 61 6c 54 69 6d 65 e . . . . . . l o c a l T i m e [2015-09-11T21:31:35+00:00] stream: TRACE > 00080: 00 2c 19 52 be 4f 01 00 00 10 6d 61 78 57 69 72 . , . R . O . . . . m a x W i r [2015-09-11T21:31:35+00:00] stream: TRACE > 00090: 65 56 65 72 73 69 6f 6e 00 03 00 00 00 10 6d 69 e V e r s i o n . . . . . . m i [2015-09-11T21:31:35+00:00] stream: TRACE > 000a0: 6e 57 69 72 65 56 65 72 73 69 6f 6e 00 00 00 00 n W i r e V e r s i o n . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 000b0: 00 01 6f 6b 00 00 00 00 00 00 00 f0 3f 00 . . o k . . . . . . . . ? . [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_readv():236 [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_read():277 [2015-09-11T21:31:35+00:00] buffer: TRACE > EXIT: _mongoc_buffer_try_append_from_stream():323 [2015-09-11T21:31:35+00:00] mongoc: TRACE > ENTRY: mongoc_topology_description_select():430 [2015-09-11T21:31:35+00:00] mongoc: TRACE > EXIT: mongoc_topology_description_select():442 [2015-09-11T21:31:35+00:00] cluster: INFO > X509: got username (username) from URI [2015-09-11T21:31:35+00:00] cluster: TRACE > ENTRY: _mongoc_cluster_run_command():105 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_writev():148 [2015-09-11T21:31:35+00:00] stream: TRACE > TRACE: mongoc_stream_writev():160 writev = 0x7f9d6696ede8 [9] [2015-09-11T21:31:35+00:00] stream: TRACE > 00000: 71 00 00 00 01 00 00 00 00 00 00 00 d4 07 00 00 q . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00010: 04 00 00 00 24 65 78 74 65 72 6e 61 6c 2e 24 63 . . . . $ e x t e r n a l . $ c [2015-09-11T21:31:35+00:00] stream: TRACE > 00020: 6d 64 00 00 00 00 00 ff ff ff ff 46 00 00 00 10 m d . . . . . . . . . F . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00030: 61 75 74 68 65 6e 74 69 63 61 74 65 00 01 00 00 a u t h e n t i c a t e . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00040: 00 02 6d 65 63 68 61 6e 69 73 6d 00 0d 00 00 00 . . m e c h a n i s m . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00050: 4d 4f 4e 47 4f 44 42 2d 58 35 30 39 00 02 75 73 M O N G O D B - X 5 0 9 . . u s [2015-09-11T21:31:35+00:00] stream: TRACE > 00060: 65 72 00 09 00 00 00 75 73 65 72 6e 61 6d 65 00 e r . . . . . u s e r n a m e . [2015-09-11T21:31:35+00:00] stream: TRACE > 00070: 00 . [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Setting timeout to: 300000 [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_writev():163 [2015-09-11T21:31:35+00:00] buffer: TRACE > ENTRY: _mongoc_buffer_append_from_stream():150 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_read():265 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_readv():225 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Setting timeout to: 300000 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Reading got: 4 wanted: 4 [2015-09-11T21:31:35+00:00] stream: TRACE > TRACE: mongoc_stream_readv():234 readv = 0x7fff3371bf90 [1] [2015-09-11T21:31:35+00:00] stream: TRACE > 00000: 57 00 00 00 W . . . [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_readv():236 [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_read():277 [2015-09-11T21:31:35+00:00] buffer: TRACE > EXIT: _mongoc_buffer_append_from_stream():186 [2015-09-11T21:31:35+00:00] buffer: TRACE > ENTRY: _mongoc_buffer_append_from_stream():150 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_read():265 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_readv():225 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Setting timeout to: 300000 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Reading got: 83 wanted: 83 [2015-09-11T21:31:35+00:00] stream: TRACE > TRACE: mongoc_stream_readv():234 readv = 0x7fff3371bf90 [1] [2015-09-11T21:31:35+00:00] stream: TRACE > 00000: c5 00 00 00 01 00 00 00 01 00 00 00 08 00 00 00 . . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00010: 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 . . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00020: 33 00 00 00 01 6f 6b 00 00 00 00 00 00 00 00 00 3 . . . . o k . . . . . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00030: 02 65 72 72 6d 73 67 00 0c 00 00 00 61 75 74 68 . e r r m s g . . . . . a u t h [2015-09-11T21:31:35+00:00] stream: TRACE > 00040: 20 66 61 69 6c 65 64 00 10 63 6f 64 65 00 12 00 f a i l e d . . c o d e . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00050: 00 00 00 . . . [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_readv():236 [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_read():277 [2015-09-11T21:31:35+00:00] buffer: TRACE > EXIT: _mongoc_buffer_append_from_stream():186 [2015-09-11T21:31:35+00:00] cluster: TRACE > TRACE: _mongoc_cluster_run_command():156 &buffer = 0x7f9d6696e550 [87] [2015-09-11T21:31:35+00:00] cluster: TRACE > 00000: 57 00 00 00 c5 00 00 00 01 00 00 00 01 00 00 00 W . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] cluster: TRACE > 00010: 08 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 . . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] cluster: TRACE > 00020: 01 00 00 00 33 00 00 00 01 6f 6b 00 00 00 00 00 . . . . 3 . . . . o k . . . . . [2015-09-11T21:31:35+00:00] cluster: TRACE > 00030: 00 00 00 00 02 65 72 72 6d 73 67 00 0c 00 00 00 . . . . . e r r m s g . . . . . [2015-09-11T21:31:35+00:00] cluster: TRACE > 00040: 61 75 74 68 20 66 61 69 6c 65 64 00 10 63 6f 64 a u t h f a i l e d . . c o d [2015-09-11T21:31:35+00:00] cluster: TRACE > 00050: 65 00 12 00 00 00 00 e . . . . . . [2015-09-11T21:31:35+00:00] cluster: TRACE > EXIT: _mongoc_cluster_run_command():179 [2015-09-11T21:31:35+00:00] cluster: TRACE > ENTRY: _mongoc_cluster_add_node():1148 [2015-09-11T21:31:35+00:00] cluster: DEBUG > Adding new server to cluster: 192.168.112.10:2300 [2015-09-11T21:31:35+00:00] cluster: INFO > X509: got username (username) from URI [2015-09-11T21:31:35+00:00] cluster: TRACE > ENTRY: _mongoc_cluster_run_command():105 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_writev():148 [2015-09-11T21:31:35+00:00] stream: TRACE > TRACE: mongoc_stream_writev():160 writev = 0x7f9d6696ede8 [9] [2015-09-11T21:31:35+00:00] stream: TRACE > 00000: 71 00 00 00 02 00 00 00 00 00 00 00 d4 07 00 00 q . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00010: 04 00 00 00 24 65 78 74 65 72 6e 61 6c 2e 24 63 . . . . $ e x t e r n a l . $ c [2015-09-11T21:31:35+00:00] stream: TRACE > 00020: 6d 64 00 00 00 00 00 ff ff ff ff 46 00 00 00 10 m d . . . . . . . . . F . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00030: 61 75 74 68 65 6e 74 69 63 61 74 65 00 01 00 00 a u t h e n t i c a t e . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00040: 00 02 6d 65 63 68 61 6e 69 73 6d 00 0d 00 00 00 . . m e c h a n i s m . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00050: 4d 4f 4e 47 4f 44 42 2d 58 35 30 39 00 02 75 73 M O N G O D B - X 5 0 9 . . u s [2015-09-11T21:31:35+00:00] stream: TRACE > 00060: 65 72 00 09 00 00 00 75 73 65 72 6e 61 6d 65 00 e r . . . . . u s e r n a m e . [2015-09-11T21:31:35+00:00] stream: TRACE > 00070: 00 . [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Setting timeout to: 300000 [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_writev():163 [2015-09-11T21:31:35+00:00] buffer: TRACE > ENTRY: _mongoc_buffer_append_from_stream():150 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_read():265 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_readv():225 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Setting timeout to: 300000 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Reading got: 4 wanted: 4 [2015-09-11T21:31:35+00:00] stream: TRACE > TRACE: mongoc_stream_readv():234 readv = 0x7fff3371bfa0 [1] [2015-09-11T21:31:35+00:00] stream: TRACE > 00000: 57 00 00 00 W . . . [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_readv():236 [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_read():277 [2015-09-11T21:31:35+00:00] buffer: TRACE > EXIT: _mongoc_buffer_append_from_stream():186 [2015-09-11T21:31:35+00:00] buffer: TRACE > ENTRY: _mongoc_buffer_append_from_stream():150 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_read():265 [2015-09-11T21:31:35+00:00] stream: TRACE > ENTRY: mongoc_stream_readv():225 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Setting timeout to: 300000 [2015-09-11T21:31:35+00:00] PHONGO: DEBUG > Reading got: 83 wanted: 83 [2015-09-11T21:31:35+00:00] stream: TRACE > TRACE: mongoc_stream_readv():234 readv = 0x7fff3371bfa0 [1] [2015-09-11T21:31:35+00:00] stream: TRACE > 00000: c6 00 00 00 02 00 00 00 01 00 00 00 08 00 00 00 . . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00010: 00 00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 . . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00020: 33 00 00 00 01 6f 6b 00 00 00 00 00 00 00 00 00 3 . . . . o k . . . . . . . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00030: 02 65 72 72 6d 73 67 00 0c 00 00 00 61 75 74 68 . e r r m s g . . . . . a u t h [2015-09-11T21:31:35+00:00] stream: TRACE > 00040: 20 66 61 69 6c 65 64 00 10 63 6f 64 65 00 12 00 f a i l e d . . c o d e . . . [2015-09-11T21:31:35+00:00] stream: TRACE > 00050: 00 00 00 . . . [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_readv():236 [2015-09-11T21:31:35+00:00] stream: TRACE > EXIT: mongoc_stream_read():277 [2015-09-11T21:31:35+00:00] buffer: TRACE > EXIT: _mongoc_buffer_append_from_stream():186 [2015-09-11T21:31:35+00:00] cluster: TRACE > TRACE: _mongoc_cluster_run_command():156 &buffer = 0x7f9d6696e550 [87] [2015-09-11T21:31:35+00:00] cluster: TRACE > 00000: 57 00 00 00 c6 00 00 00 02 00 00 00 01 00 00 00 W . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] cluster: TRACE > 00010: 08 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 . . . . . . . . . . . . . . . . [2015-09-11T21:31:35+00:00] cluster: TRACE > 00020: 01 00 00 00 33 00 00 00 01 6f 6b 00 00 00 00 00 . . . . 3 . . . . o k . . . . . [2015-09-11T21:31:35+00:00] cluster: TRACE > 00030: 00 00 00 00 02 65 72 72 6d 73 67 00 0c 00 00 00 . . . . . e r r m s g . . . . . [2015-09-11T21:31:35+00:00] cluster: TRACE > 00040: 61 75 74 68 20 66 61 69 6c 65 64 00 10 63 6f 64 a u t h f a i l e d . . c o d [2015-09-11T21:31:35+00:00] cluster: TRACE > 00050: 65 00 12 00 00 00 00 e . . . . . . [2015-09-11T21:31:35+00:00] cluster: TRACE > EXIT: _mongoc_cluster_run_command():179 [2015-09-11T21:31:35+00:00] cluster: WARNING > Failed authentication to 192.168.112.10:2300 [2015-09-11T21:31:35+00:00] cluster: TRACE > EXIT: _mongoc_cluster_add_node():1176 [2015-09-11T21:31:35+00:00] mongoc: TRACE > ENTRY: mongoc_server_description_destroy():154 [2015-09-11T21:31:35+00:00] mongoc: TRACE > EXIT: mongoc_server_description_destroy():160 [2015-09-11T21:31:35+00:00] cluster: TRACE > EXIT: _mongoc_cluster_select_by_optype():1471 [2015-09-11T21:31:35+00:00] mongoc: TRACE > EXIT: _mongoc_write_command_execute():957 [2015-09-11T21:31:35+00:00] mongoc: TRACE > GOTO: mongoc_bulk_operation_execute():429 cleanup [2015-09-11T21:31:35+00:00] mongoc: TRACE > ENTRY: _mongoc_write_result_complete():1341 [2015-09-11T21:31:35+00:00] mongoc: TRACE > EXIT: _mongoc_write_result_complete():1389 [2015-09-11T21:31:35+00:00] mongoc: TRACE > EXIT: mongoc_bulk_operation_execute():438 [2015-09-11T21:31:35+00:00] mongoc: TRACE > ENTRY: _mongoc_write_result_init():998 [2015-09-11T21:31:35+00:00] mongoc: TRACE > EXIT: _mongoc_write_result_init():1008 [2015-09-11T21:31:35+00:00] mongoc: TRACE > ENTRY: _mongoc_write_result_destroy():1015 [2015-09-11T21:31:35+00:00] mongoc: TRACE > EXIT: _mongoc_write_result_destroy():1023 MongoDB\Driver\Exception\AuthenticationException: auth failed
- is related to
-
CDRIVER-836 Only try to authenticate once on failure
- Closed
-
PHPC-407 SSL/TLS already set-up for this stream
- Closed