[SERVER-33606] mongo shell startSession() should fail if the server doesn't support logical sessions Created: 02/Mar/18  Updated: 29/Oct/23  Resolved: 03/Sep/18

Status: Closed
Project: Core Server
Component/s: Shell
Affects Version/s: 3.6.3
Fix Version/s: 3.6.9, 4.0.3, 4.1.3

Type: Bug Priority: Major - P3
Reporter: Kevin Pulo Assignee: Kevin Pulo
Resolution: Fixed Votes: 0
Labels: ShardingTechDebt
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Issue Links:
Backports
Related
related to SERVER-32064 A logical session id should be includ... Closed
Backwards Compatibility: Minor Change
Backport Requested:
v4.0, v3.6
Sprint: Sharding 2018-08-13, Sharding 2018-08-27, Sharding 2018-09-10
Participants:

 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)



 Comments   
Comment by Githook User [ 11/Oct/18 ]

Author:

{'name': 'Kevin Pulo', 'email': 'kevin.pulo@mongodb.com', 'username': 'devkev'}

Message: SERVER-33606 fail to create logical session in shell connected to old servers

Also add --disableImplicitSessions shell cmdline arg.

(cherry picked from commit 23794c14b03bb272daad7a2b25eca0b80c03a31c)
Branch: v3.6
https://github.com/mongodb/mongo/commit/8e48340301c668742a5a5bb2a8f1bb68553faaf2

Comment by Githook User [ 04/Sep/18 ]

Author:

{'name': 'Kevin Pulo', 'email': 'kevin.pulo@mongodb.com', 'username': 'devkev'}

Message: SERVER-33606 fail to create logical session in shell connected to old servers

Also add --disableImplicitSessions shell cmdline arg.

(cherry picked from commit 23794c14b03bb272daad7a2b25eca0b80c03a31c)
Branch: v4.0
https://github.com/mongodb/mongo/commit/3ce08842d5e6ec5739c2d2bd9ad0e0986b2fc379

Comment by Githook User [ 03/Sep/18 ]

Author:

{'name': 'Kevin Pulo', 'email': 'kevin.pulo@mongodb.com', 'username': 'devkev'}

Message: SERVER-33606 fail to create logical session in shell connected to old servers

Also add --disableImplicitSessions shell cmdline arg.
Branch: master
https://github.com/mongodb/mongo/commit/23794c14b03bb272daad7a2b25eca0b80c03a31c

Comment by Gregory McKeon (Inactive) [ 16/Jul/18 ]

kevin.pulo Can you pick this up?

Generated at Thu Feb 08 04:33:59 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.