Uploaded image for project: 'Core Server'
  1. Core Server
  2. SERVER-30362

JavaScript DBCollection.toString() stops working

    • Type: Icon: Bug Bug
    • Resolution: Fixed
    • Priority: Icon: Major - P3 Major - P3
    • 3.4.10, 3.5.12
    • Affects Version/s: 3.4.6, 3.5.10
    • Component/s: JavaScript
    • None
    • Fully Compatible
    • ALL
    • v3.4
    • Platforms 2017-08-21

      Calling toString() on a DBCollection object (eg. as returned by db.getCollection(...)) usually just returns the full ns as a string (via getFullName()).

      However, after a while toString() unexpectedly returns "[object DBCollection]".

      This string no doubt comes from the default SpiderMonkey/JS Object toString() function. "A while" means a few thousand calls — to be exact, it looks like 2 less than a multiple of 1100, depending on the exact conditions.

      dbcoll_tostring_1.js
      var c = db.getCollection("foo");
      for (i = 0; i < 1000000; i++) {
          assert.eq(c.toString(), "test.foo", i);
      }
      
      $ mongo dbcoll_tostring_1.js
      MongoDB shell version v3.4.6
      connecting to: mongodb://127.0.0.1:27017
      MongoDB server version: 3.4.6
      assert: ["[object DBCollection]"] != ["test.foo"] are not equal : 2197
      doassert@src/mongo/shell/assert.js:18:14
      assert.eq@src/mongo/shell/assert.js:54:5
      @dbcoll_tostring_1.js:3:1
      
      2017-07-27T13:35:30.637+1000 E QUERY    [thread1] Error: ["[object DBCollection]"] != ["test.foo"] are not equal : 2197 :
      doassert@src/mongo/shell/assert.js:18:14
      assert.eq@src/mongo/shell/assert.js:54:5
      @dbcoll_tostring_1.js:3:1
      failed to load: dbcoll_tostring_1.js
      

      As if that wasn't bizarre enough, it then continues working as normal for a while, before permanently failing. The pattern seems to involve multiples of 1100 calls.

      dbcoll_tostring_2.js
      var c = db.getCollection("foo");
      var prev = -1;
      for (i = 0; i < 1000000; i++) {
          if (c.toString() !== "test.foo") {
              print(i - prev);
              prev = i;
          }
      }
      
      $ mongo dbcoll_tostring_2.js | uniq -c
            1 MongoDB shell version v3.4.6
            1 connecting to: mongodb://127.0.0.1:27017
            1 MongoDB server version: 3.4.6
            1 2198
            1 1100
       996702 1
      

      The behaviour is deterministic.

      Disabling JIT doesn't help.

      It's something peculiar about toString() specifically. Calling getFullName() directly works as expected:

      dbcoll_tostring_3.js
      var c = db.getCollection("foo");
      for (i = 0; i < 1000000; i++) {
          assert.eq(c.getFullName(), "test.foo", i);
      }
      
      $ mongo dbcoll_tostring_3.js
      MongoDB shell version v3.4.6
      connecting to: mongodb://127.0.0.1:27017
      MongoDB server version: 3.4.6
      

      Versions:

      • 3.4 and later are affected, but 3.2 and earlier are unaffected.
      • 3.3.5 is affected, but not 3.3.4. So highly likely related to the SpiderMonkey 38 -> 45 upgrade (SERVER-23358).
      $ /m/3.3.4/bin/mongo dbcoll_tostring_2.js | uniq -c
            1 MongoDB shell version: 3.3.4
            1 connecting to: test
      $ /m/3.3.5/bin/mongo dbcoll_tostring_2.js | uniq -c
            1 MongoDB shell version: 3.3.5
            1 connecting to: test
            1 2198
            1 1100
       996702 1
      

      It's independent of which JS object is having toString() called (almost — note that this is 3298, not 2198):

      dbcoll_tostring_4.js
      var prev = -1;
      for (i = 0; i < 1000000; i++) {
          if (db.getCollection("a"+i).toString() !== "test.a"+i) {
              print(i - prev);
              prev = i;
          }
      }
      
      $ mongo dbcoll_tostring_4.js | uniq -c
            1 MongoDB shell version v3.4.6
            1 connecting to: mongodb://127.0.0.1:27017
            1 MongoDB server version: 3.4.6
            1 3298
            1 1100
       995602 1
      

      Looks like it's sensitive to the calling scope, or the call site, or at the very least related to them somehow. You can induce an extra 1100 (or 1200) successful calls by calling from a different site, eg. from another for loop, or by nesting inside a function call which is called with a unique signature (in terms of parameter types):

      dbcoll_tostring_5.js
      var prev = -1;
      for (i = 0; i < 1000000; i++) {
          if (db.getCollection("a"+i).toString() !== "test.a"+i) {
              print(i - prev);
              prev = i;
          }
      }
      var prev = -1;
      for (i = 0; i < 1000000; i++) {
          if (db.getCollection("a"+i).toString() !== "test.a"+i) {
              print(i - prev);
              prev = i;
          }
      }
      
      $ mongo dbcoll_tostring_5.js | uniq -c
            1 MongoDB shell version v3.4.6
            1 connecting to: mongodb://127.0.0.1:27017
            1 MongoDB server version: 3.4.6
            1 3298
            1 1100
       995602 1
            1 1101
            1 1100
       997799 1
      
      dbcoll_tostring_6.js
      print(db.getCollection('a0').toString());
      print(db.getCollection('a1').toString());
      print(db.getCollection('a2').toString());
      print(db.getCollection('a3').toString());
      ...
      print(db.getCollection('a999997').toString());
      print(db.getCollection('a999998').toString());
      print(db.getCollection('a999999').toString());
      
      $ awk 'BEGIN { for (i = 0; i < 1000000; i++) printf("print(db.getCollection('\''a%d'\'').toString());\n", i) }' > dbcoll_tostring_6.js
      $ mongo dbcoll_tostring_6.js | grep -v '^test\.a[0-9]\+$'
      MongoDB shell version v3.4.6
      connecting to: mongodb://127.0.0.1:27017
      MongoDB server version: 3.4.6
      
      dbcoll_tostring_7.js
      for (j = 0; j < 2; j++) {
          var prev = -1;
          for (i = 0; i < 1000000; i++) {
              if (db.getCollection("a"+i).toString() !== "test.a"+i) {
                  print(i - prev);
                  prev = i;
              }
          }
      }
      
      $ mongo dbcoll_tostring_7.js | uniq -c
            1 MongoDB shell version v3.4.6
            1 connecting to: mongodb://127.0.0.1:27017
            1 MongoDB server version: 3.4.6
            1 3597
            1 1200
       995203 1
            1 1200
       998800 1
      
      dbcoll_tostring_8.js
      var fun = function(a,b) {
          var prev = -1;
          for (i = 0; i < 1000000; i++) {
              if (db.getCollection("a"+i).toString() !== "test.a"+i) {
                  print(i - prev);
                  prev = i;
              }
          }
      };
      print("RUNNING: fun()");   fun();
      print("RUNNING: fun()");   fun();
      
      $ mongo dbcoll_tostring_8.js | uniq -c
            1 MongoDB shell version v3.4.6
            1 connecting to: mongodb://127.0.0.1:27017
            1 MongoDB server version: 3.4.6
            1 RUNNING: fun()
            1 3298
            1 1100
       995602 1
            1 RUNNING: fun()
      1000000 1
      
      dbcoll_tostring_9.js
      var fun = function(a,b) {
          print("RUNNING: fun(" + tojsononeline(a) + "," + tojsononeline(b) + ")");
          var prev = -1;
          for (i = 0; i < 1000000; i++) {
              if (db.getCollection("a"+i).toString() !== "test.a"+i) {
                  print(i - prev);
                  prev = i;
              }
          }
      };
      fun();
      fun();
      
      $ mongo dbcoll_tostring_9.js | uniq -c
            1 MongoDB shell version v3.4.6
            1 connecting to: mongodb://127.0.0.1:27017
            1 MongoDB server version: 3.4.6
            1 RUNNING: fun(undefined,undefined)
            1 3298
            1 1100
       995602 1
            1 RUNNING: fun(undefined,undefined)
            1 1100
       998900 1
      
      dbcoll_tostring_10.js
      var fun = function(a,b) {
          var prev = -1;
          for (i = 0; i < 1000000; i++) {
              if (db.getCollection("a"+i).toString() !== "test.a"+i) {
                  print(i - prev);
                  prev = i;
              }
          }
      };
      print("RUNNING: fun()");                      fun();
      print("RUNNING: fun()");                      fun();
      print("RUNNING: fun(1,2)");                   fun(1,2);
      print("RUNNING: fun(\"foo\",\"bar\")");       fun("foo","bar");
      print("RUNNING: fun(3,4)");                   fun(3,4);
      print("RUNNING: fun(\"foo\",2)");             fun("foo",2);
      print("RUNNING: fun(\"fred\",\"barney\")");   fun("fred","barney");
      print("RUNNING: fun(2,\"foo\")");             fun(2,"foo");
      print("RUNNING: fun(2,{})");                  fun(2,{});
      print("RUNNING: fun({},2)");                  fun({},2);
      
      $ mongo dbcoll_tostring_10.js | uniq -c
            1 MongoDB shell version v3.4.6
            1 connecting to: mongodb://127.0.0.1:27017
            1 MongoDB server version: 3.4.6
            1 RUNNING: fun()
            1 3298
            1 1100
       995602 1
            1 RUNNING: fun()
      1000000 1
            1 RUNNING: fun(1,2)
            1 1099
       998901 1
            1 RUNNING: fun("foo","bar")
            1 1099
       998901 1
            1 RUNNING: fun(3,4)
      1000000 1
            1 RUNNING: fun("foo",2)
      1000000 1
            1 RUNNING: fun("fred","barney")
      1000000 1
            1 RUNNING: fun(2,"foo")
      1000000 1
            1 RUNNING: fun(2,{})
            1 1099
       998901 1
            1 RUNNING: fun({},2)
            1 1099
       998901 1
      

      It seems to be peculiar to DBCollection, DB, and DBQuery. These classes have a JS toString() function. However, Mongo and Timestamp also have such a JS toString(), but aren't affected.

      dbcoll_tostring_11.js
      print(DB)
      print(DB.prototype.toString)
      print(db.toString)
      var prev = -1;
      for (i = 0; i < 1000000; i++) {
          var s = db.toString();
          if (s !== "test") {
              print(i - prev, s);
              prev = i;
          }
      }
      
      print();
      
      print(DBQuery)
      print(DBQuery.prototype.toString)
      print(db.foo.find().toString)
      var prev = -1;
      for (i = 0; i < 1000000; i++) {
          var s = db.foo.find().toString();
          if (s !== "DBQuery: test.foo -> { }") {
              print(i - prev, s);
              prev = i;
          }
      }
      
      print();
      
      print(Mongo)
      print(Mongo.prototype.toString)
      print(db.getMongo().toString)
      var prev = -1;
      for (i = 0; i < 1000000; i++) {
          var s = db.getMongo().toString();
          if (s !== "connection to 127.0.0.1:27017") {
              print(i - prev, s);
              prev = i;
          }
      }
      
      print();
      
      print(Timestamp)
      print(Timestamp.prototype.toString)
      print(Timestamp(1, 2).toString)
      var prev = -1;
      for (i = 0; i < 1000000; i++) {
          var s = Timestamp(1, 2).toString();
          if (s !== "Timestamp(1, 2)") {
              print(i - prev, s);
              prev = i;
          }
      }
      
      print();
      
      print(Timestamp)
      print(Timestamp.prototype.toString)
      print((new Timestamp(1, 2)).toString)
      var prev = -1;
      for (i = 0; i < 1000000; i++) {
          var s = (new Timestamp(1, 2)).toString();
          if (s !== "Timestamp(1, 2)") {
              print(i - prev, s);
              prev = i;
          }
      }
      
      $ mongo dbcoll_tostring_11.js | uniq -c
            1 MongoDB shell version v3.4.6
            1 connecting to: mongodb://127.0.0.1:27017
            1 MongoDB server version: 3.4.6
            1 function DB() {
            1     [native code]
            1 }
            1 function () {
            1         return this._name;
            1     }
            1 function () {
            1         return this._name;
            1     }
            1 2198 [object DB]
            1 1100 [object DB]
       996702 1 [object DB]
            1
            1 function DBQuery() {
            1     [native code]
            1 }
            1 function () {
            1     return "DBQuery: " + this._ns + " -> " + tojson(this._query);
            1 }
            1 function () {
            1     return "DBQuery: " + this._ns + " -> " + tojson(this._query);
            1 }
            1 2201 [object DBQuery]
            1 1100 [object DBQuery]
       996699 1 [object DBQuery]
            1
            1 function Mongo() {
            1     [native code]
            1 }
            1 function () {
            1     return "connection to " + this.host;
            1 }
            1 function () {
            1     return "connection to " + this.host;
            1 }
            1
            1 function Timestamp() {
            1     [native code]
            1 }
            1 function () {
            1         return "Timestamp(" + this.t + ", " + this.i + ")";
            1     }
            1 function () {
            1         return "Timestamp(" + this.t + ", " + this.i + ")";
            1     }
            1
            1 function Timestamp() {
            1     [native code]
            1 }
            1 function () {
            1         return "Timestamp(" + this.t + ", " + this.i + ")";
            1     }
            1 function () {
            1         return "Timestamp(" + this.t + ", " + this.i + ")";
            1     }
      

      I ran into this while working on an unrelated jstest:

      ...
      collNum++;
      var collName = "coll" + collNum;
      var coll = db.getCollection(collName);
      ...
      assert.commandWorked(coll.createIndex({ i: 1 }));
      assert.commandWorked(s.s0.adminCommand({shardcollection: coll.toString(), key: {i: 1}}));
      ...
      
      ...
      [js_test:SERVER-20392] 2017-07-26T04:19:24.108+0000 s20014| 2017-07-26T04:19:24.107+0000 D COMMAND  [conn1] AllShardsCollectionCommand: test.coll4 cmd:{ createIndexes: "coll4", indexes: [ { key: { i: 1.0 }, name: "i_1" } ], $db: "test" }
      [js_test:SERVER-20392] 2017-07-26T04:19:24.116+0000 d20010| 2017-07-26T04:19:24.116+0000 I INDEX    [conn8] build index on: test.coll4 properties: { v: 2, key: { i: 1.0 }, name: "i_1", ns: "test.coll4" }
      [js_test:SERVER-20392] 2017-07-26T04:19:24.116+0000 d20010| 2017-07-26T04:19:24.116+0000 I INDEX    [conn8]      building index using bulk method; build may temporarily use up to 500 megabytes of RAM
      [js_test:SERVER-20392] 2017-07-26T04:19:24.137+0000 d20010| 2017-07-26T04:19:24.137+0000 I INDEX    [conn8] build index done.  scanned 8192 total records. 0 secs
      [js_test:SERVER-20392] 2017-07-26T04:19:24.138+0000 s20014| 2017-07-26T04:19:24.138+0000 D -        [conn1] User Assertion: 73:Invalid namespace specified '[object DBCollection]' src/mongo/db/commands.cpp 99
      [js_test:SERVER-20392] 2017-07-26T04:19:24.139+0000 assert: command failed: {
      [js_test:SERVER-20392] 2017-07-26T04:19:24.139+0000     "ok" : 0,
      [js_test:SERVER-20392] 2017-07-26T04:19:24.139+0000     "errmsg" : "Invalid namespace specified '[object DBCollection]'",
      [js_test:SERVER-20392] 2017-07-26T04:19:24.139+0000     "code" : 73,
      [js_test:SERVER-20392] 2017-07-26T04:19:24.139+0000     "codeName" : "InvalidNamespace"
      [js_test:SERVER-20392] 2017-07-26T04:19:24.139+0000 } : undefined
      [js_test:SERVER-20392] 2017-07-26T04:19:24.140+0000 _getErrorWithCode@src/mongo/shell/utils.js:25:13
      [js_test:SERVER-20392] 2017-07-26T04:19:24.140+0000 doassert@src/mongo/shell/assert.js:16:14
      [js_test:SERVER-20392] 2017-07-26T04:19:24.140+0000 assert.commandWorked@src/mongo/shell/assert.js:403:5
      [js_test:SERVER-20392] 2017-07-26T04:19:24.140+0000 runCase@jstests/sharding/SERVER-20392.js:64:1
      [js_test:SERVER-20392] 2017-07-26T04:19:24.140+0000 @jstests/sharding/SERVER-20392.js:163:1
      [js_test:SERVER-20392] 2017-07-26T04:19:24.140+0000 @jstests/sharding/SERVER-20392.js:4:2
      

      Directly calling getFullName() instead of toString() is an adequate workaround in this case, but in general there may be a lot of toString() call sites already in existence.

      I'm also concerned that this may be merely a symptom of some deeper problem.

            Assignee:
            mark.benvenuto@mongodb.com Mark Benvenuto
            Reporter:
            kevin.pulo@mongodb.com Kevin Pulo
            Votes:
            0 Vote for this issue
            Watchers:
            11 Start watching this issue

              Created:
              Updated:
              Resolved: