[SERVER-36024] Invariant when using logical sessions and auditing Created: 09/Jul/18  Updated: 29/Oct/23  Resolved: 29/Mar/19

Status: Closed
Project: Core Server
Component/s: Internal Code
Affects Version/s: 4.1.1
Fix Version/s: 4.1.10

Type: Bug Priority: Major - P3
Reporter: Spencer Jackson Assignee: Andrew Morrow (Inactive)
Resolution: Fixed Votes: 0
Labels: None
Remaining Estimate: Not Specified
Time Spent: Not Specified
Original Estimate: Not Specified

Backwards Compatibility: Fully Compatible
Operating System: ALL
Sprint: Dev Tools 2018-10-08, Dev Tools 2018-10-22, Dev Tools 2018-11-19, Dev Tools 2018-12-03, Dev Tools 2018-12-17, Dev Tools 2018-12-31, Dev Tools 2019-01-14, Dev Tools 2019-01-28, Dev Tools 2019-02-11, Dev Tools 2019-03-25, Dev Tools 2019-04-08
Participants:

 Description   

The server crashes with an invariant failure, in the following scenario:

1) Start the server with ./mongod --auditDestination console --setParameter auditAuthorizationSuccess=true

2) Start a shell, run an operation, close the shell, start another shell. (Just trying to trigger an update to the logical session cache)

3) Wait 5 minutes.

Backtrace is as follows:

2018-07-09T11:32:16.658-0400 F -        [LogicalSessionCacheRefresh] Invariant failure impl.doesNotAlias(fieldName) src/mongo/bson/mutable/document.cpp 2516
2018-07-09T11:32:16.658-0400 F -        [LogicalSessionCacheRefresh]
 
***aborting after invariant() failure
 
 
2018-07-09T11:32:16.735-0400 F -        [LogicalSessionCacheRefresh] Got signal: 6 (Aborted).
 0x556176e76783 0x556176e760d5 0x556176e759a9 0x7fe420cc3a80 0x7fe42092c86b 0x7fe42091740e 0x556176e6675e 0x5561745f543c 0x556176dcbc23 0x556176dcbb65 0x556174e1958c 0x556174e1ab19 0x5561765b4f78 0x5561765baa84 0x5561765b11ed 0x5561765b3e27 0x5561747408bc 0x55617473e9ae 0x55617473b93d 0x55617473a653 0x556174725d79 0x55617620ff6b 0x55617620fc5c 0x5561765d4751 0x5561765d4edc 0x5561765d3a20 0x5561764df36e 0x5561764df065 0x5561764e38da 0x5561764e1b83 0x5561764e18ae 0x5561764e1599 0x5561764de53f 0x5561764de355 0x556174c9c168 0x5561764cf9c3 0x5561764d0af3 0x5561764d1e60 0x5561764d1d12 0x556175e42484 0x556175e3f263 0x556175e3f0cd 0x556175e3f05d 0x556175e3f035 0x556175e3f005 0x556175e3eef9 0x7fe4211a2d4f 0x7fe420cb9075 0x7fe4209ee53f                                                                                                            
----- BEGIN BACKTRACE -----
{"backtrace":[{"b":"55617112E000","o":"5D48783","s":"_ZN5mongo15printStackTraceERSo"},{"b":"55617112E000","o":"5D480D5"},{"b":"55617112E000","o":"5D479A9"},{"b":"7FE420CB2000","o":"11A80"},{"b":"7FE4208F6000","o":"3686B","s":"gsignal"},{"b":"7FE4208F6000","o":"2140E","s":"abort"},{"b":"55617112E000","o":"5D3875E","s":"_ZN5mongo15invariantFailedEPKcS1_j"},{"b":"55617112E000","o":"34C743C","s":"_ZN5mongo21invariantWithLocationIbEEvRKT_PKcS5_j"},{"b":"55617112E000","o":"5C9DC23","s":"_ZN5mongo11mutablebson8Document14makeElementIntENS_10StringDataEi"},{"b":"55617112E000","o":"5C9DB65","s":"_ZN5mongo11mutablebson7Element11setValueIntEi"},{"b":"55617112E000","o":"3CEB58C"},{"b":"55617112E000","o":"3CECB19"},{"b":"55617112E000","o":"5486F78"},{"b":"55617112E000","o":"548CA84","s":"_ZN5mongo5audit20logCommandAuthzCheckEPNS_6ClientERKNS_12OpMsgRequestERKNS0_16CommandInterfaceENS_10ErrorCodes5ErrorE"},{"b":"55617112E000","o":"54831ED","s":"_ZN5mongo14CommandHelpers17auditLogAuthEventEPNS_16OperationContextEPKNS_17CommandInvocationERKNS_12OpMsgRequestENS_10ErrorCodes5ErrorE"},{"b":"55617112E000","o":"5485E27","s":"_ZNK5mongo17CommandInvocation18checkAuthorizationEPNS_16OperationContextERKNS_12OpMsgRequestE"},{"b":"55617112E000","o":"36128BC"},{"b":"55617112E000","o":"36109AE"},{"b":"55617112E000","o":"360D93D"},{"b":"55617112E000","o":"360C653","s":"_ZN5mongo23ServiceEntryPointCommon13handleRequestEPNS_16OperationContextERKNS_7MessageERKNS0_5HooksE"},{"b":"55617112E000","o":"35F7D79","s":"_ZN5mongo23ServiceEntryPointMongod13handleRequestEPNS_16OperationContextERKNS_7MessageE"},{"b":"55617112E000","o":"50E1F6B"},{"b":"55617112E000","o":"50E1C5C","s":"_ZN5mongo14DBDirectClient4callERNS_7MessageES2_bPNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE"},{"b":"55617112E000","o":"54A6751","s":"_ZN5mongo12DBClientBase20runCommandWithTargetENS_12OpMsgRequestE"},{"b":"55617112E000","o":"54A6EDC","s":"_ZN5mongo12DBClientBase20runCommandWithTargetERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEENS_7BSONObjERS9_i"},{"b":"55617112E000","o":"54A5A20","s":"_ZN5mongo12DBClientBase10runCommandERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEENS_7BSONObjERS9_i"},{"b":"55617112E000","o":"53B136E"},{"b":"55617112E000","o":"53B1065"},{"b":"55617112E000","o":"53B58DA","s":"_ZNKSt8functionIFN5mongo6StatusENS0_7BSONObjEEEclES2_"},{"b":"55617112E000","o":"53B3B83"},{"b":"55617112E000","o":"53B38AE"},{"b":"55617112E000","o":"53B3599"},{"b":"55617112E000","o":"53B053F"},{"b":"55617112E000","o":"53B0355","s":"_ZN5mongo18SessionsCollection8doRemoveERKNS_15NamespaceStringERKSt13unordered_setINS_16LogicalSessionIdENS_20LogicalSessionIdHashESt8equal_toIS5_ESaIS5_EESt8functionIFNS_6StatusENS_7BSONObjEEE"},{"b":"55617112E000","o":"3B6E168","s":"_ZN5mongo28SessionsCollectionStandalone13removeRecordsEPNS_16OperationContextERKSt13unordered_setINS_16LogicalSessionIdENS_20LogicalSessionIdHashESt8equal_toIS4_ESaIS4_EE"},{"b":"55617112E000","o":"53A19C3","s":"_ZN5mongo23LogicalSessionCacheImpl8_refreshEPNS_6ClientE"},{"b":"55617112E000","o":"53A2AF3","s":"_ZN5mongo23LogicalSessionCacheImpl16_periodicRefreshEPNS_6ClientE"},{"b":"55617112E000","o":"53A3E60"},{"b":"55617112E000","o":"53A3D12"},{"b":"55617112E000","o":"4D14484","s":"_ZNKSt8functionIFvPN5mongo6ClientEEEclES2_"},{"b":"55617112E000","o":"4D11263"},{"b":"55617112E000","o":"4D110CD"},{"b":"55617112E000","o":"4D1105D"},{"b":"55617112E000","o":"4D11035"},{"b":"55617112E000","o":"4D11005"},{"b":"55617112E000","o":"4D10EF9"},{"b":"7FE4210E8000","o":"BAD4F"},{"b":"7FE420CB2000","o":"7075"},{"b":"7FE4208F6000","o":"F853F","s":"clone"}],"processInfo":{ "mongodbVersion" : "0.0.0", "gitVersion" : "unknown", "compiledModules" : [ "ninja", "enterprise" ], "uname" : { "sysname" : "Linux", "release" : "4.16.13-2-ARCH", "version" : "#1 SMP PREEMPT Fri Jun 1 18:46:11 UTC 2018", "machine" : "x86_64" }, "somap" : [ { "b" : "55617112E000", "elfType" : 3, "buildId" : "A1B9EF34C2C9232E" }, { "b" : "7FFF55965000", "path" : "linux-vdso.so.1", "elfType" : 3, "buildId" : "D87D4E5C0366D21D0F54AA52A124A34F84124FF1" }, { "b" : "7FE423BD0000", "path" : "/usr/lib/libnetsnmpmibs.so.30", "elfType" : 3, "buildId" : "36CB3E11B40D15C53001C086F8FAAB0B4C1CE00D" }, { "b" : "7FE4239C3000", "path" : "/usr/lib/libpci.so.3", "elfType" : 3, "buildId" : "0C066C3E7F43CEA11A5E352824439AC0A828E93D" }, { "b" : "7FE4237BF000", "path" : "/usr/lib/libdl.so.2", "elfType" : 3, "buildId" : "B1F7828E5EDA69D750388BD4C57B7313C31D0689" }, { "b" : "7FE42355B000", "path" : "/usr/lib/libnetsnmpagent.so.30", "elfType" : 3, "buildId" : "4440AACD15ACD4660E1A00ECE750A9FA22AE3A77" }, { "b" : "7FE423278000", "path" : "/usr/lib/libnetsnmp.so.30", "elfType" : 3, "buildId" : "3CDC36D1B9E5C6E52A3FA5BA15C91DC5A07F7665" }, { "b" : "7FE422DFB000", "path" : "/usr/lib/libcrypto.so.1.1", "elfType" : 3, "buildId" : "D5E444BC9086E431202D79533CA1F2C1A2B4B749" }, { "b" : "7FE422BDA000", "path" : "/usr/lib/libnl-3.so.200", "elfType" : 3, "buildId" : "EE3703026E25C17DC166DD706A858B2262ADE7B3" }, { "b" : "7FE422845000", "path" : "/usr/lib/libm.so.6", "elfType" : 3, "buildId" : "FE4619624EECA222D4C441C32E83A422319775B8" }, { "b" : "7FE4225FB000", "path" : "/usr/lib/libldap-2.4.so.2", "elfType" : 3, "buildId" : "7AAABD83ED0678E33F05D4F7CB2B2D644590AC6A" }, { "b" : "7FE4223EC000", "path" : "/usr/lib/liblber-2.4.so.2", "elfType" : 3, "buildId" : "12B0EE032AA091FCFAB5D661DB358469211B88E3" }, { "b" : "7FE4221D0000", "path" : "/usr/lib/libsasl2.so.3",
"elfType" : 3, "buildId" : "C831D9E5F09E4CD6B6332FEAC451EEAC672C0763" }, { "b" : "7FE421F82000", "path" : "/usr/lib/libgssapi_krb5.so.2", "elfType" : 3, "buildId" : "D0A33667BD6487179E7A6CF94235656CC9B4435A" }, { "b" : "7FE421D02000", "path" : "/usr/lib/libcurl.so.4", "elfType" : 3, "buildId" : "0146CAA23573901C422E804BFB30AE0B05BFE5CF" }, { "b" : "7FE421AEB000", "path" : "/usr/lib/libresolv.so.2", "elfType" : 3, "buildId" : "725142EB8E5ADAD7A0CCB47E2966043F46F76EC7" }, { "b" : "7FE421881000", "path" : "/usr/lib/libssl.so.1.1", "elfType" : 3, "buildId" : "4C4CDF293CCA5A21CADF82327E06EF6A22CED92D" }, { "b" : "7FE421679000", "path" : "/usr/lib/librt.so.1", "elfType" : 3, "buildId" : "245207D442DF08DD2907C30AF2CB9B8A13B51A27" }, { "b" : "7FE421471000", "path" : "/usr/lib/libatomic.so.1", "elfType" : 3, "buildId" : "529D5308AFF48E1ECFE1865A4AC347B4FA5851B0" }, { "b" : "7FE4210E8000", "path" : "/usr/lib/libstdc++.so.6", "elfType" : 3, "buildId" : "DC499F9FDD93658B30E30874F64093737F1FF6B7" }, { "b" : "7FE420ED0000", "path" : "/usr/lib/libgcc_s.so.1", "elfType" : 3, "buildId" : "35716FE0D4439F03B8B33E38CE87864D7415CF6E" }, { "b" : "7FE420CB2000", "path" : "/usr/lib/libpthread.so.0", "elfType" : 3, "buildId" : "068F89B101CAC015ECCBC26C4F314CFCE272875E" }, { "b" : "7FE4208F6000", "path" : "/usr/lib/libc.so.6", "elfType" : 3, "buildId" : "0C1ECB7B0E67918D1D1991E0E7793F814BFA1EC2" }, { "b" : "7FE4204F2000", "path" : "/usr/lib/perl5/5.26/core_perl/CORE/libperl.so", "elfType" : 3, "buildId" : "E5FE795E777ABC891052CB8540BF603BD38BC1E8" }, { "b" : "7FE4202DA000", "path" : "/usr/lib/libnsl.so.2", "elfType" : 3, "buildId" : "9F7155F939BF2801A05769BB9CE24B74D75778A5" }, { "b" : "7FE4200A2000", "path" : "/usr/lib/libcrypt.so.1", "elfType" : 3, "buildId" : "3A71FD0E35C824A5E6D955A00E5C1D3BC15090A6" }, { "b" : "7FE41FE9F000", "path" : "/usr/lib/libutil.so.1", "elfType" : 3, "buildId" : "4A8D247EE26504E821C0864BB52A39F45681A216" }, { "b" : "7FE41FC81000", "path" : "/usr/lib/libudev.so.1", "elfType" : 3, "buildId" : "10142E5CDF5DD0DCE4E89DB11ABD8772E478CFE1" }, { "b" : "7FE424049000", "path" : "/lib64/ld-linux-x86-64.so.2", "elfType" : 3, "buildId" : "FDA54F3D41633F4DB27D791ADFCA514CFFB7C8A6" }, { "b" : "7FE41F998000", "path" : "/usr/lib/libkrb5.so.3", "elfType" : 3, "buildId" : "1F00C885585BE1A1BC3110C456E3A26644F61401" }, { "b" : "7FE41F765000", "path" : "/usr/lib/libk5crypto.so.3", "elfType" : 3, "buildId" : "E7492ED071855B6FBADE1350FDF5A9D0F6931C3E" }, { "b" : "7FE41F561000", "path" : "/usr/lib/libcom_err.so.2", "elfType" : 3, "buildId" : "CE8653BC29335817239232FD1C66F2EED6C74C1C" }, { "b" : "7FE41F354000", "path" : "/usr/lib/libkrb5support.so.0", "elfType" : 3, "buildId" : "9851265DEF826012332D0175AD6994E6213C57EC" }, { "b" : "7FE41F150000", "path" : "/usr/lib/libkeyutils.so.1", "elfType" : 3, "buildId" : "ACB874EAB11A955E0D26FEB11530B5E64F4B038D" }, { "b" : "7FE41EF2B000", "path" : "/usr/lib/libnghttp2.so.14", "elfType" : 3, "buildId" : "32D26A702610044EB8DDB581ABAAC359DF98FA37" }, { "b" : "7FE41ED0E000", "path" : "/usr/lib/libidn2.so.0", "elfType" : 3, "buildId" : "0D69AF2DC2CBFD676172D88B626637144E156229" }, { "b" : "7FE41EAFE000", "path" : "/usr/lib/libpsl.so.5", "elfType" : 3, "buildId" : "87B10307B9E6A8CB44DD52CC82665221E9DADC29" }, { "b" : "7FE41E8E7000", "path" : "/usr/lib/libz.so.1", "elfType" : 3, "buildId" : "9D65B31D958D72054843331A9D549B1D12ADA045" }, { "b" : "7FE41E6B6000", "path" : "/usr/lib/libtirpc.so.3", "elfType" : 3, "buildId" : "2B001F0DADCC90A48F71E2EC9A7CA3AF4B896D73" }, { "b" : "7FE41E336000", "path" : "/usr/lib/libunistring.so.2", "elfType" : 3, "buildId" : "B06A573A55F6005E92418F30945B13581F9BC848" } ] }}                                                                                                                     
 mongod(_ZN5mongo15printStackTraceERSo+0x33) [0x556176e76783]
 mongod(+0x5D480D5) [0x556176e760d5]
 mongod(+0x5D479A9) [0x556176e759a9]
 libpthread.so.0(+0x11A80) [0x7fe420cc3a80]
 libc.so.6(gsignal+0x10B) [0x7fe42092c86b]
 libc.so.6(abort+0x129) [0x7fe42091740e]
 mongod(_ZN5mongo15invariantFailedEPKcS1_j+0x17E) [0x556176e6675e]
 mongod(_ZN5mongo21invariantWithLocationIbEEvRKT_PKcS5_j+0x3C) [0x5561745f543c]
 mongod(_ZN5mongo11mutablebson8Document14makeElementIntENS_10StringDataEi+0x73) [0x556176dcbc23]
 mongod(_ZN5mongo11mutablebson7Element11setValueIntEi+0xD5) [0x556176dcbb65]
 mongod(+0x3CEB58C) [0x556174e1958c]
 mongod(+0x3CECB19) [0x556174e1ab19]
 mongod(+0x5486F78) [0x5561765b4f78]
 mongod(_ZN5mongo5audit20logCommandAuthzCheckEPNS_6ClientERKNS_12OpMsgRequestERKNS0_16CommandInterfaceENS_10ErrorCodes5ErrorE+0x354) [0x5561765baa84]
 mongod(_ZN5mongo14CommandHelpers17auditLogAuthEventEPNS_16OperationContextEPKNS_17CommandInvocationERKNS_12OpMsgRequestENS_10ErrorCodes5ErrorE+0xBD) [0x5561765b11ed]
 mongod(_ZNK5mongo17CommandInvocation18checkAuthorizationEPNS_16OperationContextERKNS_12OpMsgRequestE+0x327) [0x5561765b3e27]
 mongod(+0x36128BC) [0x5561747408bc]
 mongod(+0x36109AE) [0x55617473e9ae]
 mongod(+0x360D93D) [0x55617473b93d]
 mongod(_ZN5mongo23ServiceEntryPointCommon13handleRequestEPNS_16OperationContextERKNS_7MessageERKNS0_5HooksE+0x543) [0x55617473a653]
 mongod(_ZN5mongo23ServiceEntryPointMongod13handleRequestEPNS_16OperationContextERKNS_7MessageE+0x69) [0x556174725d79]
 mongod(+0x50E1F6B) [0x55617620ff6b]
 mongod(_ZN5mongo14DBDirectClient4callERNS_7MessageES2_bPNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEE+0x4C) [0x55617620fc5c]
 mongod(_ZN5mongo12DBClientBase20runCommandWithTargetENS_12OpMsgRequestE+0x311) [0x5561765d4751]
 mongod(_ZN5mongo12DBClientBase20runCommandWithTargetERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEENS_7BSONObjERS9_i+0xDC) [0x5561765d4edc]
 mongod(_ZN5mongo12DBClientBase10runCommandERKNSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEENS_7BSONObjERS9_i+0x70) [0x5561765d3a20]
 mongod(+0x53B136E) [0x5561764df36e]
 mongod(+0x53B1065) [0x5561764df065]
 mongod(_ZNKSt8functionIFN5mongo6StatusENS0_7BSONObjEEEclES2_+0x6A) [0x5561764e38da]
 mongod(+0x53B3B83) [0x5561764e1b83]
 mongod(+0x53B38AE) [0x5561764e18ae]
 mongod(+0x53B3599) [0x5561764e1599]
 mongod(+0x53B053F) [0x5561764de53f]
 mongod(_ZN5mongo18SessionsCollection8doRemoveERKNS_15NamespaceStringERKSt13unordered_setINS_16LogicalSessionIdENS_20LogicalSessionIdHashESt8equal_toIS5_ESaIS5_EESt8functionIFNS_6StatusENS_7BSONObjEEE+0x85) [0x5561764de355]
 mongod(_ZN5mongo28SessionsCollectionStandalone13removeRecordsEPNS_16OperationContextERKSt13unordered_setINS_16LogicalSessionIdENS_20LogicalSessionIdHashESt8equal_toIS4_ESaIS4_EE+0xC8) [0x556174c9c168]
 mongod(_ZN5mongo23LogicalSessionCacheImpl8_refreshEPNS_6ClientE+0x923) [0x5561764cf9c3]
 mongod(_ZN5mongo23LogicalSessionCacheImpl16_periodicRefreshEPNS_6ClientE+0x33) [0x5561764d0af3]
 mongod(+0x53A3E60) [0x5561764d1e60]
 mongod(+0x53A3D12) [0x5561764d1d12]
 mongod(_ZNKSt8functionIFvPN5mongo6ClientEEEclES2_+0x64) [0x556175e42484]
 mongod(+0x4D11263) [0x556175e3f263]
 mongod(+0x4D110CD) [0x556175e3f0cd]
 mongod(+0x4D1105D) [0x556175e3f05d]
 mongod(+0x4D11035) [0x556175e3f035]
 mongod(+0x4D11005) [0x556175e3f005]
 mongod(+0x4D10EF9) [0x556175e3eef9]
 libstdc++.so.6(+0xBAD4F) [0x7fe4211a2d4f]
 libpthread.so.0(+0x7075) [0x7fe420cb9075]
 libc.so.6(clone+0x3F) [0x7fe4209ee53f]
-----  END BACKTRACE  -----
zsh: abort (core dumped)  ./mongod --auditDestination console --setParameter



 Comments   
Comment by Githook User [ 29/Mar/19 ]

Author:

{'email': 'acm@mongodb.com', 'name': 'Andrew Morrow', 'username': 'acmorrow'}

Message: SERVER-36024 Relax overzealous dassert in mutable bson
Branch: master
https://github.com/mongodb/mongo/commit/1cbf42b163d3a3760462b113941ff27192fa274f

Comment by Gregory McKeon (Inactive) [ 27/Aug/18 ]

acm do we plan on doing perf testing here/doing a more expansive fix to avoid the use-after-free?

Comment by Andrew Morrow (Inactive) [ 02/Aug/18 ]

spencer.jackson Provided the following repro:

TEST(Document, RegressionCheck) {
      mongo::BSONObj obj(BSON("x" << BSON_ARRAY("y" << "z")));
      mmb::Document doc(obj, mmb::Document::kInPlaceDisabled);
 
      auto array = doc.makeElementArray("foo");
      ASSERT_OK(array.appendObject(StringData(), BSON("baz" <<
"bar")));
      ASSERT_OK(doc.root().pushBack(array));
 
      mmb::Element root = doc.root();
      mmb::Element field = root.findFirstChildNamed("foo");
 
      ASSERT_OK(field.setValueInt(field.countChildren()));
  }

Comment by Janna Golden [ 02/Aug/18 ]

Sending this back to Platforms - this triggers a dassert in mutablebson stemming from redactFromLogging(). I talked with spencer.jackson who suggested this may be due to the OP_MSG changes in auditing resulting in mutablebson objects being created that don't pass this dassert.

Generated at Thu Feb 08 04:41:47 UTC 2024 using Jira 9.7.1#970001-sha1:2222b88b221c4928ef0de3161136cc90c8356a66.