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

Noisy log message, "Received interrupt request for unknown op"

    • Type: Icon: Bug Bug
    • Resolution: Fixed
    • Priority: Icon: Minor - P4 Minor - P4
    • 4.9.0
    • Affects Version/s: None
    • Component/s: None
    • Fully Compatible
    • ALL
    • Query 2020-10-19, Query 2020-11-02, Query 2020-11-16

      Log message 22790 appear a little while ago, and in a typical test it constitutes a large fraction of all log messages:

      [js_test:migrateBig_balancer] 2020-09-07T08:22:40.599+0000 s20025| 2020-09-07T08:22:40.592+00:00 I  COMMAND  51803   [conn13] "Slow query","attr":{"type":"command","ns":"test.stuff","appName":"MongoDB Shell","command":{"insert":"stuff","ordered":false,"lsid":{"id":{"$uuid":"ddf2a4f1-3008-4095-84ff-9300c385fceb"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1599466960,"i":1}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$db":"test"},"nShards":1,"ninserted":1,"numYields":0,"reslen":170,"protocol":"op_msg","durationMillis":155}
      [js_test:migrateBig_balancer] 2020-09-07T08:22:40.600+0000 s20025| 2020-09-07T08:22:40.593+00:00 D1 QUERY    22790   [conn13] "Received interrupt request for unknown op","attr":{"opId":54}
      [js_test:migrateBig_balancer] 2020-09-07T08:22:40.905+0000 d20021| 2020-09-07T08:22:40.904+00:00 I  STORAGE  22402   [OplogCapMaintainerThread-local.oplog.rs] "WiredTiger record store oplog truncation finished","attr":{"durationMillis":0}
      [js_test:migrateBig_balancer] 2020-09-07T08:22:40.905+0000 s20025| 2020-09-07T08:22:40.905+00:00 I  COMMAND  51803   [conn13] "Slow query","attr":{"type":"command","ns":"test.stuff","appName":"MongoDB Shell","command":{"insert":"stuff","ordered":false,"lsid":{"id":{"$uuid":"ddf2a4f1-3008-4095-84ff-9300c385fceb"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1599466960,"i":2}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$db":"test"},"nShards":1,"ninserted":1,"numYields":0,"reslen":170,"protocol":"op_msg","durationMillis":153}
      [js_test:migrateBig_balancer] 2020-09-07T08:22:40.906+0000 s20025| 2020-09-07T08:22:40.905+00:00 D1 QUERY    22790   [conn13] "Received interrupt request for unknown op","attr":{"opId":55}
      [js_test:migrateBig_balancer] 2020-09-07T08:22:41.227+0000 s20025| 2020-09-07T08:22:41.227+00:00 I  COMMAND  51803   [conn13] "Slow query","attr":{"type":"command","ns":"test.stuff","appName":"MongoDB Shell","command":{"insert":"stuff","ordered":false,"lsid":{"id":{"$uuid":"ddf2a4f1-3008-4095-84ff-9300c385fceb"}},"$clusterTime":{"clusterTime":{"$timestamp":{"t":1599466960,"i":3}},"signature":{"hash":{"$binary":{"base64":"AAAAAAAAAAAAAAAAAAAAAAAAAAA=","subType":"0"}},"keyId":0}},"$db":"test"},"nShards":1,"ninserted":1,"numYields":0,"reslen":170,"protocol":"op_msg","durationMillis":158}
      [js_test:migrateBig_balancer] 2020-09-07T08:22:41.228+0000 s20025| 2020-09-07T08:22:41.227+00:00 D1 QUERY    22790   [conn13] "Received interrupt request for unknown op","attr":{"opId":56}
      

      Can we lower this message's log level, or log it only occasionally, or reduce the frequency of the event it's logging about?

            Assignee:
            andrew.paroski@mongodb.com Drew Paroski
            Reporter:
            jesse@mongodb.com A. Jesse Jiryu Davis
            Votes:
            3 Vote for this issue
            Watchers:
            10 Start watching this issue

              Created:
              Updated:
              Resolved: