Details
-
Bug
-
Resolution: Fixed
-
Major - P3
-
3.6.3
-
Minor Change
-
v4.0, v3.6
-
Sharding 2018-08-13, Sharding 2018-08-27, Sharding 2018-09-10
Description
Currently db.getMongo().startSession() succeeds and generates a session id when connected to an old server. However the wire protocol checks mean that this session id is never actually used (ie. never actually sent to the server), and so operations sent via the session object also silently succeed (likely old servers would just ignore the lsid field even if it was sent).
This all conspires to give the false impression that the operations being performed will be part of a logical session. The expected behaviour is that if the server doesn't support logical sessions, then startSession() should throw an exception.
For example, expose the wire protocol checking functions/consts in SessionAwareClient (kWireVersionSupporting* and serverSupports()), and then check the wire version in the ServerSession constructor (after creating the SessionAwareClient but before calling _startSession() on it).
3.6.3 with verbose log:
$ mongo --port 23456 --norc
|
MongoDB shell version v3.6.3
|
connecting to: mongodb://127.0.0.1:23456/
|
MongoDB server version: 3.6.3
|
> session = db.getMongo().startSession()
|
session { "id" : UUID("29f3064b-10dd-4d8f-835a-0a88cd418266") }
|
> session.getDatabase("test").foo.insert({})
|
WriteResult({ "nInserted" : 1 })
|
> session.getDatabase("test").foo.find()
|
{ "_id" : ObjectId("5a98c4e41f7838043549f9a1") }
|
> db.runCommand({startSession:1})
|
{
|
"id" : {
|
"id" : UUID("dcbd3bbf-9c04-49d8-8ad9-d49cf88327e2")
|
},
|
"timeoutMinutes" : 30,
|
"ok" : 1
|
}
|
>
|
bye
|
2018-03-02T14:28:23.712+1100 I NETWORK [listener] connection accepted from 127.0.0.1:52462 #6 (1 connection now open)
|
2018-03-02T14:28:23.713+1100 I NETWORK [conn6] received client metadata from 127.0.0.1:52462 conn: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.6.3" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "16.04" } }
|
2018-03-02T14:28:23.713+1100 I COMMAND [conn6] command admin.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1, client: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.6.3" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "16.04" } }, $db: "admin" } numYields:0 reslen:223 locks:{} protocol:op_query 0ms
|
2018-03-02T14:28:23.713+1100 I COMMAND [conn6] command admin.$cmd appName: "MongoDB Shell" command: whatsmyuri { whatsmyuri: 1, $db: "admin" } numYields:0 reslen:47 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:28:23.715+1100 I COMMAND [conn6] command admin.$cmd appName: "MongoDB Shell" command: buildInfo { buildinfo: 1.0, $db: "admin" } numYields:0 reslen:1270 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:28:23.717+1100 I COMMAND [conn6] command admin.$cmd appName: "MongoDB Shell" command: getLog { getLog: "startupWarnings", $db: "admin" } numYields:0 reslen:1661 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:28:23.718+1100 I COMMAND [conn6] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0, $db: "test" } numYields:0 reslen:208 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:28:23.719+1100 I COMMAND [conn6] command test.$cmd appName: "MongoDB Shell" command: buildInfo { buildInfo: 1.0, $db: "test" } numYields:0 reslen:1270 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:28:23.720+1100 I COMMAND [conn6] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0, $db: "test" } numYields:0 reslen:208 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:28:23.720+1100 I COMMAND [conn6] command admin.$cmd appName: "MongoDB Shell" command: replSetGetStatus { replSetGetStatus: 1.0, forShell: 1.0, $db: "admin" } numYields:0 reslen:106 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:28:29.077+1100 I COMMAND [conn6] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0, $db: "test" } numYields:0 reslen:208 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:28:36.357+1100 I COMMAND [conn6] command config.transactions appName: "MongoDB Shell" command: find { find: "transactions", filter: { _id: { id: UUID("29f3064b-10dd-4d8f-835a-0a88cd418266"), uid: BinData(0, E3B0C44298FC1C149AFBF4C8996FB92427AE41E4649B934CA495991B7852B855) } }, ntoreturn: 1, singleBatch: true, $db: "config" } planSummary: EOF keysExamined:0 docsExamined:0 cursorExhausted:1 numYields:0 nreturned:0 reslen:92 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_msg 0ms
|
2018-03-02T14:28:36.358+1100 D - [conn6] reloading view catalog for database test
|
2018-03-02T14:28:36.358+1100 D STORAGE [conn6] create collection test.foo {}
|
2018-03-02T14:28:36.358+1100 I STORAGE [conn6] createCollection: test.foo with generated UUID: be030971-65a0-4fa5-94d7-4011dc553ade
|
2018-03-02T14:28:36.358+1100 D STORAGE [conn6] stored meta data for test.foo @ RecordId(5)
|
2018-03-02T14:28:36.383+1100 D STORAGE [conn6] test.foo: clearing plan cache - collection info cache reset
|
2018-03-02T14:28:36.383+1100 D STORAGE [conn6] create uri: table:index-8-7315913501069923330 config: type=file,internal_page_max=16k,leaf_page_max=16k,checksum=on,prefix_compression=true,block_compressor=,,,,key_format=u,value_format=u,app_metadata=(formatVersion=8,infoObj={ "v" : 2, "key" : { "_id" : 1 }, "name" : "_id_", "ns" : "test.foo" }),log=(enabled=true)
|
2018-03-02T14:28:36.407+1100 D STORAGE [conn6] test.foo: clearing plan cache - collection info cache reset
|
2018-03-02T14:28:36.407+1100 I COMMAND [conn6] command test.foo appName: "MongoDB Shell" command: insert { insert: "foo", ordered: true, lsid: { id: UUID("29f3064b-10dd-4d8f-835a-0a88cd418266") }, $db: "test" } ninserted:1 keysInserted:1 numYields:0 reslen:29 locks:{ Global: { acquireCount: { r: 5, w: 3 } }, Database: { acquireCount: { r: 1, w: 2, W: 1 } }, Collection: { acquireCount: { r: 1, w: 2 } } } protocol:op_msg 49ms
|
2018-03-02T14:28:36.408+1100 I COMMAND [conn6] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0, $db: "test" } numYields:0 reslen:208 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:28:56.359+1100 I COMMAND [conn6] command test.foo appName: "MongoDB Shell" command: find { find: "foo", filter: {}, lsid: { id: UUID("29f3064b-10dd-4d8f-835a-0a88cd418266") }, $db: "test" } planSummary: COLLSCAN keysExamined:0 docsExamined:1 cursorExhausted:1 numYields:0 nreturned:1 reslen:106 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_msg 1ms
|
2018-03-02T14:28:56.360+1100 I COMMAND [conn6] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0, $db: "test" } numYields:0 reslen:208 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:29:03.990+1100 I COMMAND [conn6] command test.$cmd appName: "MongoDB Shell" command: startSession { startSession: 1.0, $db: "test" } numYields:0 reslen:76 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:29:03.991+1100 I COMMAND [conn6] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0, $db: "test" } numYields:0 reslen:208 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:29:04.871+1100 I COMMAND [conn6] command admin.$cmd appName: "MongoDB Shell" command: endSessions { endSessions: [ { id: UUID("29f3064b-10dd-4d8f-835a-0a88cd418266") } ], $db: "admin" } numYields:0 reslen:22 locks:{} protocol:op_msg 0ms
|
2018-03-02T14:29:04.871+1100 I NETWORK [conn6] end connection 127.0.0.1:52462 (0 connections now open)
|
3.4.13 with verbose log:
$ mongo --port 12345 --norc
|
MongoDB shell version v3.6.3
|
connecting to: mongodb://127.0.0.1:12345/
|
MongoDB server version: 3.4.13
|
WARNING: shell and server versions do not match
|
> session = db.getMongo().startSession()
|
session { "id" : UUID("513af8ae-f902-4c07-979a-a939812f368b") }
|
> session.getDatabase("test").foo.insert({})
|
WriteResult({ "nInserted" : 1 })
|
> session.getDatabase("test").foo.find()
|
{ "_id" : ObjectId("5a98c64b3012b89e79da8491") }
|
> db.runCommand({startSession:1})
|
{
|
"ok" : 0,
|
"errmsg" : "no such command: 'startSession', bad cmd: '{ startSession: 1.0 }'",
|
"code" : 59,
|
"codeName" : "CommandNotFound"
|
}
|
>
|
bye
|
2018-03-02T14:34:28.206+1100 I NETWORK [thread1] connection accepted from 127.0.0.1:52532 #8 (1 connection now open)
|
2018-03-02T14:34:28.206+1100 I NETWORK [conn8] received client metadata from 127.0.0.1:52532 conn8: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.6.3" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "16.04" } }
|
2018-03-02T14:34:28.206+1100 I COMMAND [conn8] command admin.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1, client: { application: { name: "MongoDB Shell" }, driver: { name: "MongoDB Internal Client", version: "3.6.3" }, os: { type: "Linux", name: "Ubuntu", architecture: "x86_64", version: "16.04" } } } numYields:0 reslen:189 locks:{} protocol:op_query 0ms
|
2018-03-02T14:34:28.206+1100 I COMMAND [conn8] command admin.$cmd appName: "MongoDB Shell" command: whatsmyuri { whatsmyuri: 1 } numYields:0 reslen:47 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:28.207+1100 I COMMAND [conn8] command admin.$cmd appName: "MongoDB Shell" command: buildInfo { buildinfo: 1.0 } numYields:0 reslen:1250 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:28.207+1100 I COMMAND [conn8] command admin.$cmd appName: "MongoDB Shell" command: getLog { getLog: "startupWarnings" } numYields:0 reslen:800 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:28.208+1100 I COMMAND [conn8] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0 } numYields:0 reslen:174 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:28.208+1100 I COMMAND [conn8] command test.$cmd appName: "MongoDB Shell" command: buildInfo { buildInfo: 1.0 } numYields:0 reslen:1250 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:28.208+1100 I COMMAND [conn8] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0 } numYields:0 reslen:174 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:28.209+1100 I COMMAND [conn8] command admin.$cmd appName: "MongoDB Shell" command: replSetGetStatus { replSetGetStatus: 1.0, forShell: 1.0 } numYields:0 reslen:106 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:32.308+1100 I COMMAND [conn8] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0 } numYields:0 reslen:174 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:35.940+1100 D - [conn8] reloading view catalog for database test
|
2018-03-02T14:34:35.940+1100 D STORAGE [conn8] create collection test.foo {}
|
2018-03-02T14:34:35.940+1100 D STORAGE [conn8] stored meta data for test.foo @ RecordId(4)
|
2018-03-02T14:34:35.960+1100 D STORAGE [conn8] test.foo: clearing plan cache - collection info cache reset
|
2018-03-02T14:34:35.960+1100 D STORAGE [conn8] create uri: table:index-6--2894484955783166514 config: type=file,internal_page_max=16k,leaf_page_max=16k,checksum=on,prefix_compression=true,block_compressor=,,,,key_format=u,value_format=u,app_metadata=(formatVersion=8,infoObj={ "v" : 2, "key" : { "_id" : 1 }, "name" : "_id_", "ns" : "test.foo" }),
|
2018-03-02T14:34:35.988+1100 D STORAGE [conn8] test.foo: clearing plan cache - collection info cache reset
|
2018-03-02T14:34:35.989+1100 I COMMAND [conn8] command test.foo appName: "MongoDB Shell" command: insert { insert: "foo", ordered: true, documents: [ { _id: ObjectId('5a98c64b3012b89e79da8491') } ] } ninserted:1 keysInserted:1 numYields:0 reslen:29 locks:{ Global: { acquireCount: { r: 3, w: 3 } }, Database: { acquireCount: { w: 2, W: 1 } }, Collection: { acquireCount: { w: 2 } } } protocol:op_command 49ms
|
2018-03-02T14:34:35.990+1100 I COMMAND [conn8] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0 } numYields:0 reslen:174 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:39.284+1100 I COMMAND [conn8] command test.foo appName: "MongoDB Shell" command: find { find: "foo", filter: {} } planSummary: COLLSCAN keysExamined:0 docsExamined:1 cursorExhausted:1 numYields:0 nreturned:1 reslen:106 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_command 0ms
|
2018-03-02T14:34:39.285+1100 I COMMAND [conn8] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0 } numYields:0 reslen:174 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:43.355+1100 D - [conn8] User Assertion: 59:no such command: 'startSession', bad cmd: '{ startSession: 1.0 }' src/mongo/db/run_commands.cpp 59
|
2018-03-02T14:34:43.355+1100 D COMMAND [conn8] assertion while executing command 'startSession' on database 'test': 59 no such command: 'startSession', bad cmd: '{ startSession: 1.0 }'
|
2018-03-02T14:34:43.355+1100 I COMMAND [conn8] command test.$cmd appName: "MongoDB Shell" command: { startSession: 1.0 } exception: no such command: 'startSession', bad cmd: '{ startSession: 1.0 }' code:59 numYields:0 reslen:140 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:43.356+1100 I COMMAND [conn8] command test.$cmd appName: "MongoDB Shell" command: isMaster { isMaster: 1.0, forShell: 1.0 } numYields:0 reslen:174 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:44.947+1100 D - [conn8] User Assertion: 59:no such command: 'endSessions', bad cmd: '{ endSessions: [ { id: BinData(4, 513AF8AEF9024C07979AA939812F368B) } ] }' src/mongo/db/run_commands.cpp 59
|
2018-03-02T14:34:44.947+1100 D COMMAND [conn8] assertion while executing command 'endSessions' on database 'admin': 59 no such command: 'endSessions', bad cmd: '{ endSessions: [ { id: BinData(4, 513AF8AEF9024C07979AA939812F368B) } ] }'
|
2018-03-02T14:34:44.947+1100 I COMMAND [conn8] command admin.$cmd appName: "MongoDB Shell" command: { endSessions: [ { id: BinData(4, 513AF8AEF9024C07979AA939812F368B) } ] } exception: no such command: 'endSessions', bad cmd: '{ endSessions: [ { id: BinData(4, 513AF8AEF9024C07979AA939812F368B) } ] }' code:59 numYields:0 reslen:191 locks:{} protocol:op_command 0ms
|
2018-03-02T14:34:44.948+1100 I - [conn8] end connection 127.0.0.1:52532 (1 connection now open)
|
Attachments
Issue Links
- related to
-
SERVER-32064 A logical session id should be included in all command requests from the mongo shell
-
- Closed
-