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

Field names should be quoted in logs

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major - P3
    • Resolution: Done
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: Logging
    • Labels:
      None
    • Operating System:
      ALL
    • Sprint:
      Dev Tools 2020-01-13, Dev Tools 2020-01-27, Dev Tools 2020-02-10

      Description

      Lack of quoting means it can be impossible to tell what the query actually is.

      Real example:

      2015-11-20T16:46:35.074-0500 I COMMAND  [conn1166] command foo.bar command: find { find: "bar", filter: {  _id: "foobar" }, shardVersion: [ Timestamp 2000|7, ObjectId('564fd7ca4529a9f9b23074ed') ] } planSummary: COLLSCAN keysExamined:0 docsExamined:344866188 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:2694991 nreturned:0 reslen:216 locks:{ Global: { acquireCount: { r: 5389984 } }, Database: { acquireCount: { r: 2694992 } }, Collection: { acquireCount: { r: 2694992 } } } protocol:op_command 1173549ms
      

      Why is this query using a COLLSCAN instead of IDHACK? Because the query is actually on the field " _id".

      Contrived example:
      What's the difference between these queries?

      2015-11-21T22:24:19.430+1100 I COMMAND  [conn29] command test.foo command: find { find: "foo", filter: { abc: 1.0, def: 1.0, a: 1.0 }, shardVersion: [ Timestamp 2000|7, ObjectId('564fd7ca4529a9f9b23074ed') ] } planSummary: IXSCAN { a: "hashed" } keysExamined:4 docsExamined:4 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:0 reslen:211 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_command 0ms
      2015-11-21T22:26:40.657+1100 I COMMAND  [conn30] command test.foo command: find { find: "foo", filter: { abc: 1.0, def: 1.0, a: 1.0 }, shardVersion: [ Timestamp 2000|7, ObjectId('564fd7ca4529a9f9b23074ed') ] } planSummary: IXSCAN { a: "hashed" } keysExamined:4 docsExamined:4 cursorExhausted:1 keyUpdates:0 writeConflicts:0 numYields:0 nreturned:0 reslen:211 locks:{ Global: { acquireCount: { r: 2 } }, Database: { acquireCount: { r: 1 } }, Collection: { acquireCount: { r: 1 } } } protocol:op_command 0ms
      

      They look identical, but were generated by the (very different) queries:

      db.foo.find({abc: 1, def : 1, a:1})
      db.foo.find({'abc: 1.0, def' : 1, a:1})
      

        Attachments

          Issue Links

            Activity

              People

              Assignee:
              henrik.edin Henrik Edin
              Reporter:
              joanna.cheng Joanna Cheng
              Participants:
              Votes:
              1 Vote for this issue
              Watchers:
              10 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: