Uploaded image for project: 'Documentation'
  1. Documentation
  2. DOCS-13974

Investigate changes in SERVER-51068: HierarchicalAcquisitionLevelViolation messages are cryptic

    XMLWordPrintableJSON

Details

    Description

      Description

      Downstream Change Summary

      Latch violations now have different error messages. The details about where the violated latch was instantiated have been reorganized and expanded. The new log message upon error looks like so:
      {
      "t":

      Unknown macro: { "$date"}

      ,
      "s":"F",
      "c":"-",
      "id":5106803,
      "ctx":"main",
      "msg":"Theoretical deadlock found on use of latch",
      "attr":{
      "reason":"Latch released before other latch of lower level",
      "latch":

      Unknown macro: { "name"}

      ,
      }
      }

      Description of Linked Ticket

      What actually happened here? I can't figure it out. I don't think the code being reported on is incorrect, but maybe it is. I can't tell from this message. The diagnostic feature should be able to explain what its expectations were and how they were unmet.

      Clearly there was a deadlock concern that was triggered. I think this message should try to answer some basic questions to be useful. Which locks were involved? What order were they acquired? Why is that a concern? Right now I just have no idea what's wrong.

      [js_test:agg_expr_fuzzer-1278c-1600474428419-0] 2020-09-19T00:13:59.732+0000 d20020| 2020-09-19T00:13:59.731+00:00 F - 23093 [initandlisten] "Fatal assertion","attr": { msgid: 31360, error: "HierarchicalAcquisitionLevelViolation: Theoretical deadlock alert - InvalidWasPresent latch acquisition at src/mongo/util/synchronized_value.h:149 on latch synchronized_value::_mutex", file: "src/mongo/util/latch_analyzer.cpp", line: 231 }

      https://logkeeper.mongodb.org/lobster/build/1fe9647b6f97d7b1cbc3f12477d979cd/test/5f654d43c2ab684a40168b65#bookmarks=0%2C39%2C71

      This is stated in terms of implementation details of the latch analyzer. As someone who's just writing lock and unlock statements, I really shouldn't have to drill into the enums and figure out how it happened. Much richer information is available to the site that threw the assertion, but wasn't brought out in the log statement.

      It looks like all the synchronized_value objects in the codebase will have the same identity string. It would be helpful in this case to have known what T was.

      Scope of changes

      Impact to Other Docs

      MVP (Work and Date)

      Resources (Scope or Design Docs, Invision, etc.)

      Attachments

        Activity

          People

            andrew.feierabend@mongodb.com Andrew Feierabend (Inactive)
            backlog-server-pm Backlog - Core Eng Program Management Team
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:
              3 years, 13 weeks, 5 days ago