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

Log gets incorrectly truncated in case of long $in list

    XMLWordPrintable

    Details

    • Type: Improvement
    • Status: Open
    • Priority: Major - P3
    • Resolution: Unresolved
    • Affects Version/s: 4.4.4
    • Fix Version/s: Backlog
    • Component/s: Logging
    • Labels:
      None
    • Case:

      Description

      When there is a long $in list the log gets incorrectly truncated losing other fields filter information.

      In order to reproduce this problem you can run:

      foo=[]
      N=1620
      for (var i = 1; i <= N; i++) { foo.push(i); }
      db.foo.insert({a:1})
      db.foo.createIndex({a:1,b:1})
      db.setProfilingLevel(0,-1)
      db.foo.find({b:1,c:{$in:foo},a:1})
      

      The generated log is something like:

      {"t":{"$date":"2021-03-17T20:30:07.212+01:00"},"s":"I",  "c":"COMMAND",  "id":51803,   "ctx":"conn9","msg":"Slow query","attr":{"type":"command","ns":"test.foo","appName":"MongoDB Shell","command":{"find":"foo","filter":{"b":1.0,"c":{"$in":[1.0,.... 1612.0,1613.0,1614.0]}}},"planSummary":"IXSCAN { a: 1, b: 1 }","keysExamined":0,"docsExamined":0,"cursorExhausted":true,"numYields":0,"nreturned":0,"queryHash":"B67CED3E","planCacheKey":"0B3D0365","reslen":97,"locks":{"ReplicationStateTransition":{"acquireCount":{"w":1}},"Global":{"acquireCount":{"r":1}},"Database":{"acquireCount":{"r":1}},"Collection":{"acquireCount":{"r":1}},"Mutex":{"acquireCount":{"r":1}}},"storage":{},"protocol":"op_msg","durationMillis":0},"truncated":{"command":{"filter":{"c":{"$in":{"1614":{"type":"double","size":8}}}}}},"size":{"command":21692}}
      

      As you can notice the filter on "a" is missing from the log, and we only have the filter on "b" and "c" even using an index on "a:1, b:1", making difficult to understand why this specific index was used

        Attachments

          Activity

            People

            Assignee:
            backlog-server-security Backlog - Security Team
            Reporter:
            renato.riccio Renato Riccio
            Participants:
            Votes:
            1 Vote for this issue
            Watchers:
            9 Start watching this issue

              Dates

              Created:
              Updated: