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

Old pymongo version 3.10.1 on MongoDB v5.0 causes Invariant failure (message.operation() == dbMsg) after connection reset by peer

    XMLWordPrintable

Details

    • Bug
    • Status: Closed
    • Critical - P2
    • Resolution: Fixed
    • 5.0.9
    • 4.4.17, 5.0.12
    • None
    • Fully Compatible
    • ALL
    • v4.4
    • Service Arch 2022-08-22

    Description

      A request over a very slow connection (South America to Northern Europe: RTT 220ms, throughput ~10Mbps) seems to have triggered an invariant failure after the remote end hung up.

      Connection 1:

      {"t":{"$date":"2022-07-13T13:50:25.648Z"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn66597","msg":"client metadata","attr":{"remote":"10.20.55.1:62396","client":"conn66597","doc":{"driver":{"name":"PyMongo","version":"3.10.1"},"os":{"type":"Windows","name":"Windows 10","architecture":"AMD64","version":"10.0.22000-SP0"},"platform":"CPython 3.9.13.final.0"}}}
      {"t":{"$date":"2022-07-13T13:50:26.666Z"},"s":"I",  "c":"ACCESS",   "id":20250,   "ctx":"conn66597","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":false,"principalName":"reader","authenticationDatabase":"<DATABASE>","remote":"10.20.55.1:62396","extraInfo":{}}}
      {"t":{"$date":"2022-07-13T13:58:09.753Z"},"s":"I",  "c":"NETWORK",  "id":22989,   "ctx":"conn66597","msg":"Error sending response to client. Ending connection from remote","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection reset by peer"},"remote":"10.20.55.1:62396","connectionId":66597}}
      {"t":{"$date":"2022-07-13T13:58:09.756Z"},"s":"F",  "c":"-",        "id":23079,   "ctx":"conn66597","msg":"Invariant failure","attr":{"expr":"message.operation() == dbMsg","file":"src/mongo/rpc/op_msg.cpp","line":133}}
      {"t":{"$date":"2022-07-13T13:58:09.757Z"},"s":"F",  "c":"-",        "id":23080,   "ctx":"conn66597","msg":"\n\n***aborting after invariant() failure\n\n"}
      {"t":{"$date":"2022-07-13T13:58:09.758Z"},"s":"F",  "c":"CONTROL",  "id":4757800, "ctx":"conn66597","msg":"Writing fatal message","attr":{"message":"Got signal: 6 (Aborted).\n"}}
      {"t":{"$date":"2022-07-13T13:58:09.964Z"},"s":"I",  "c":"CONTROL",  "id":31380,   "ctx":"conn66597","msg":"BACKTRACE","attr":{"bt":{"backtrace":[{"a":"55BB2BF5BE75","b":"55BB2809E000","o":"3EBDE75","s":"_ZN5mongo18stack_trace_detail12_GLOBAL__N_119printStackTraceImplERKNS1_7OptionsEPNS_14StackTraceSinkE.constprop.357","s+":"215"},{"a":"55BB2BF5E909","b":"55BB2809E000","o":"3EC0909","s":"_ZN5mongo15printStackTraceEv","s+":"29"},{"a":"55BB2BF56F46","b":"55BB2809E000","o":"3EB8F46","s":"abruptQuit","s+":"66"},{"a":"7FB3E1A51420","b":"7FB3E1A3D000","o":"14420","s":"funlockfile","s+":"60"},{"a":"7FB3E188E00B","b":"7FB3E184B000","o":"4300B","s":"gsignal","s+":"CB"},{"a":"7FB3E186D859","b":"7FB3E184B000","o":"22859","s":"abort","s+":"12B"},{"a":"55BB29468FAE","b":"55BB2809E000","o":"13CAFAE","s":"_ZN5mongo15invariantFailedEPKcS1_j","s+":"F7"},{"a":"55BB293B05A2","b":"55BB2809E000","o":"13125A2","s":"_ZN5mongo5OpMsg5parseERKNS_7MessageE.cold.429","s+":"644"},{"a":"55BB29670CE6","b":"55BB2809E000","o":"15D2CE6","s":"_ZN5mongo9transport19ServiceStateMachine4Impl23cleanupExhaustResourcesEv","s+":"66"},{"a":"55BB29671545","b":"55BB2809E000","o":"15D3545","s":"_ZN5mongo9transport19ServiceStateMachine4Impl14cleanupSessionERKNS_6StatusE","s+":"95"},{"a":"55BB28F4B908","b":"55BB2809E000","o":"EAD908","s":"_ZN5mongo9transport19ServiceStateMachine4Impl15scheduleNewLoopENS_6StatusE.cold.860","s+":"150"},{"a":"55BB29671AB4","b":"55BB2809E000","o":"15D3AB4","s":"_ZN5mongo14future_details4callIRZNS_9transport19ServiceStateMachine4Impl12startNewLoopERKNS_6StatusEEUlS5_E2_EEDaOT_NS_10StatusWithINS0_8FakeVoidEEE","s+":"34"},{"a":"55BB29671E03","b":"55BB2809E000","o":"15D3E03","s":"_ZN5mongo9transport19ServiceStateMachine4Impl12startNewLoopERKNS_6StatusE","s+":"283"},{"a":"55BB2967222F","b":"55BB2809E000","o":"15D422F","s":"_ZZN5mongo15unique_functionIFvNS_6StatusEEE8makeImplIZNS_9transport19ServiceStateMachine4Impl15scheduleNewLoopES1_EUlS1_E_EEDaOT_EN12SpecificImpl4callEOS1_","s+":"7F"},{"a":"55BB29D51ED3","b":"55BB2809E000","o":"1CB3ED3","s":"_ZZN5mongo15unique_functionIFvvEE8makeImplIZNS_9transport15ServiceExecutor8scheduleENS0_IFvNS_6StatusEEEEEUlvE_EEDaOT_EN12SpecificImpl4callEv","s+":"33"},{"a":"55BB2B70DB7B","b":"55BB2809E000","o":"366FB7B","s":"_ZZN5mongo15unique_functionIFvvEE8makeImplIZNS_9transport26ServiceExecutorSynchronous12scheduleTaskES2_NS4_15ServiceExecutor13ScheduleFlagsEEUlvE0_EEDaOT_EN12SpecificImpl4callEv","s+":"BB"},{"a":"55BB2B711A2C","b":"55BB2809E000","o":"3673A2C","s":"_ZZN5mongo15unique_functionIFvvEE8makeImplIZNS_25launchServiceWorkerThreadES2_EUlvE2_EEDaOT_EN12SpecificImpl4callEv","s+":"5C"},{"a":"55BB2B711A9C","b":"55BB2809E000","o":"3673A9C","s":"_ZN5mongo12_GLOBAL__N_17runFuncEPv","s+":"1C"},{"a":"7FB3E1A45609","b":"7FB3E1A3D000","o":"8609","s":"start_thread","s+":"D9"},{"a":"7FB3E196A133","b":"7FB3E184B000","o":"11F133","s":"clone","s+":"43"}],"processInfo":{"mongodbVersion":"5.0.9","gitVersion":"6f7dae919422dcd7f4892c10ff20cdc721ad00e6","compiledModules":[],"uname":{"sysname":"Linux","release":"5.4.0-121-generic","version":"#137-Ubuntu SMP Wed Jun 15 13:33:07 UTC 2022","machine":"x86_64"},"somap":[{"b":"55BB2809E000","elfType":3,"buildId":"EEB6C6E4767A2FF4A2F77AE4A23FCBFE4981C02D"},{"b":"7FB3E1A3D000","path":"/lib/x86_64-linux-gnu/libpthread.so.0","elfType":3,"buildId":"7B4536F41CDAA5888408E82D0836E33DCF436466"},{"b":"7FB3E184B000","path":"/lib/x86_64-linux-gnu/libc.so.6","elfType":3,"buildId":"1878E6B475720C7C51969E69AB2D276FAE6D1DEE"}]}}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB2BF5BE75","b":"55BB2809E000","o":"3EBDE75","s":"_ZN5mongo18stack_trace_detail12_GLOBAL__N_119printStackTraceImplERKNS1_7OptionsEPNS_14StackTraceSinkE.constprop.357","s+":"215"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB2BF5E909","b":"55BB2809E000","o":"3EC0909","s":"_ZN5mongo15printStackTraceEv","s+":"29"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB2BF56F46","b":"55BB2809E000","o":"3EB8F46","s":"abruptQuit","s+":"66"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"7FB3E1A51420","b":"7FB3E1A3D000","o":"14420","s":"funlockfile","s+":"60"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"7FB3E188E00B","b":"7FB3E184B000","o":"4300B","s":"gsignal","s+":"CB"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"7FB3E186D859","b":"7FB3E184B000","o":"22859","s":"abort","s+":"12B"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB29468FAE","b":"55BB2809E000","o":"13CAFAE","s":"_ZN5mongo15invariantFailedEPKcS1_j","s+":"F7"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB293B05A2","b":"55BB2809E000","o":"13125A2","s":"_ZN5mongo5OpMsg5parseERKNS_7MessageE.cold.429","s+":"644"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB29670CE6","b":"55BB2809E000","o":"15D2CE6","s":"_ZN5mongo9transport19ServiceStateMachine4Impl23cleanupExhaustResourcesEv","s+":"66"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB29671545","b":"55BB2809E000","o":"15D3545","s":"_ZN5mongo9transport19ServiceStateMachine4Impl14cleanupSessionERKNS_6StatusE","s+":"95"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB28F4B908","b":"55BB2809E000","o":"EAD908","s":"_ZN5mongo9transport19ServiceStateMachine4Impl15scheduleNewLoopENS_6StatusE.cold.860","s+":"150"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB29671AB4","b":"55BB2809E000","o":"15D3AB4","s":"_ZN5mongo14future_details4callIRZNS_9transport19ServiceStateMachine4Impl12startNewLoopERKNS_6StatusEEUlS5_E2_EEDaOT_NS_10StatusWithINS0_8FakeVoidEEE","s+":"34"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB29671E03","b":"55BB2809E000","o":"15D3E03","s":"_ZN5mongo9transport19ServiceStateMachine4Impl12startNewLoopERKNS_6StatusE","s+":"283"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB2967222F","b":"55BB2809E000","o":"15D422F","s":"_ZZN5mongo15unique_functionIFvNS_6StatusEEE8makeImplIZNS_9transport19ServiceStateMachine4Impl15scheduleNewLoopES1_EUlS1_E_EEDaOT_EN12SpecificImpl4callEOS1_","s+":"7F"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB29D51ED3","b":"55BB2809E000","o":"1CB3ED3","s":"_ZZN5mongo15unique_functionIFvvEE8makeImplIZNS_9transport15ServiceExecutor8scheduleENS0_IFvNS_6StatusEEEEEUlvE_EEDaOT_EN12SpecificImpl4callEv","s+":"33"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB2B70DB7B","b":"55BB2809E000","o":"366FB7B","s":"_ZZN5mongo15unique_functionIFvvEE8makeImplIZNS_9transport26ServiceExecutorSynchronous12scheduleTaskES2_NS4_15ServiceExecutor13ScheduleFlagsEEUlvE0_EEDaOT_EN12SpecificImpl4callEv","s+":"BB"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB2B711A2C","b":"55BB2809E000","o":"3673A2C","s":"_ZZN5mongo15unique_functionIFvvEE8makeImplIZNS_25launchServiceWorkerThreadES2_EUlvE2_EEDaOT_EN12SpecificImpl4callEv","s+":"5C"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"55BB2B711A9C","b":"55BB2809E000","o":"3673A9C","s":"_ZN5mongo12_GLOBAL__N_17runFuncEPv","s+":"1C"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"7FB3E1A45609","b":"7FB3E1A3D000","o":"8609","s":"start_thread","s+":"D9"}}}
      {"t":{"$date":"2022-07-13T13:58:09.965Z"},"s":"I",  "c":"CONTROL",  "id":31445,   "ctx":"conn66597","msg":"Frame","attr":{"frame":{"a":"7FB3E196A133","b":"7FB3E184B000","o":"11F133","s":"clone","s+":"43"}}},
      

      Connection 2:

      {"t":{"$date":"2022-07-13T13:50:29.255Z"},"s":"I",  "c":"NETWORK",  "id":51800,   "ctx":"conn66604","msg":"client metadata","attr":{"remote":"10.20.55.1:55624","client":"conn66604","doc":{"driver":{"name":"PyMongo","version":"3.10.1"},"os":{"type":"Windows","name":"Windows 10","architecture":"AMD64","version":"10.0.22000-SP0"},"platform":"CPython 3.9.13.final.0"}}}
      {"t":{"$date":"2022-07-13T13:50:30.238Z"},"s":"I",  "c":"ACCESS",   "id":20250,   "ctx":"conn66604","msg":"Authentication succeeded","attr":{"mechanism":"SCRAM-SHA-256","speculative":false,"principalName":"reader","authenticationDatabase":"<DATABASE>","remote":"10.20.55.1:55624","extraInfo":{}}}
      {"t":{"$date":"2022-07-13T13:58:09.753Z"},"s":"I",  "c":"NETWORK",  "id":22989,   "ctx":"conn66604","msg":"Error sending response to client. Ending connection from remote","attr":{"error":{"code":6,"codeName":"HostUnreachable","errmsg":"Connection reset by peer"},"remote":"10.20.55.1:55624","connectionId":66604}}
      {"t":{"$date":"2022-07-13T13:58:09.757Z"},"s":"F",  "c":"-",        "id":23079,   "ctx":"conn66604","msg":"Invariant failure","attr":{"expr":"message.operation() == dbMsg","file":"src/mongo/rpc/op_msg.cpp","line":133}}
      {"t":{"$date":"2022-07-13T13:58:09.757Z"},"s":"F",  "c":"-",        "id":23080,   "ctx":"conn66604","msg":"\n\n***aborting after invariant() failure\n\n"}
      {"t":{"$date":"2022-07-13T13:58:09.966Z"},"s":"F",  "c":"CONTROL",  "id":4757800, "ctx":"conn66604","msg":"Writing fatal message","attr":{"message":"Got signal: 6 (Aborted).\n"}}
      

      Attachments

        1. diagnostic.data.tar.gz
          472 kB
        2. image-2022-07-20-16-06-43-364.png
          image-2022-07-20-16-06-43-364.png
          43 kB

        Issue Links

          Activity

            People

              george.wangensteen@mongodb.com George Wangensteen
              anders.wenhaug@solutionseeker.no Anders Wenhaug
              Votes:
              2 Vote for this issue
              Watchers:
              16 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: