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

executor log line isn't useful

    • Type: Icon: Bug Bug
    • Resolution: Fixed
    • Priority: Icon: Major - P3 Major - P3
    • 7.1.0-rc0, 7.0.0-rc4
    • Affects Version/s: 6.3.1
    • Component/s: None
    • Labels:
      None
    • Service Arch
    • Fully Compatible
    • ALL
    • v7.0
    • Service Arch 2023-05-29, Service Arch 2023-06-12

      With the upgrade to 6.3, the "Client's executor exceed time limit" log line is appearing as a large percentage of log lines in all Serverless MTM logs. The units in the variables aren't useful to compare, so all the log lines look the same:

      {"t":{"$date":"2023-04-18T20:14:45.328+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn132","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:15:17.288+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn132","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:15:49.584+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn126","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:16:30.991+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn130","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:16:57.926+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn129","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:23:53.518+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn129","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:25:07.888+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn128","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:26:04.580+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn129","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:29:08.836+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn129","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:33:53.093+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn130","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:36:54.710+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn128","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:38:48.453+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn127","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:39:01.341+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn130","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:39:16.014+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn130","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:40:41.788+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn131","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:40:44.824+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn130","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:41:46.159+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn131","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:44:04.368+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn131","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:45:24.320+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn132","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:47:06.455+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn131","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:47:14.312+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn128","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:48:57.930+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn128","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:53:09.731+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn128","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:54:52.420+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn99","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      {"t":{"$date":"2023-04-18T20:56:19.113+00:00"},"s":"I",  "c":"-",        "id":4651401, "ctx":"conn130","msg":"Client's executor exceeded time limit","attr":{"elapsedMillis":1,"limitMicros":30}}
      

      We should either suppress these log lines, or make them more useful by changing how we measure the executor time.

            Assignee:
            jason.chan@mongodb.com Jason Chan
            Reporter:
            milkie@mongodb.com Eric Milkie
            Votes:
            1 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: