Uploaded image for project: 'PHP Driver: Extension'
  1. PHP Driver: Extension
  2. PHPC-415

Failed authentication causes re-authentication attempt

    • Type: Icon: Bug Bug
    • Resolution: Done
    • Priority: Icon: Major - P3 Major - P3
    • 1.0.0-beta2
    • 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
      

            Assignee:
            bjori Hannes Magnusson
            Reporter:
            bjori Hannes Magnusson
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

              Created:
              Updated:
              Resolved: